Creating a new format tutorial

275 views
Skip to first unread message

Mike Laster

unread,
Jul 13, 2019, 2:05:02 PM7/13/19
to lnav
Are there any guides anywhere for how to go about creating a new format?

I'm trying to add a format for the macOS .logarchive file.  I can convert it to plain text with "log show --style compact" and get logs that look like this:

2019-06-10 16:42:12.571 Df wcd[60:451] [com.apple.wcd:WC] Starting up                                                                                                              │

I have my JSON file created and it no longer has parse errors, but it isn't used either.  When I point Lnav at my log file it still parses as generic_log, not my custom "example_log" format.

This is my JSON:

{
    "example_log" : {
        "title" : "Example Log Format",
        "description" : "Log format used in the documentation example.",
        "url" : "http://example.com/log-format.html",
        "regex" : {
            // "header": {
            //     "pattern" : "^Timestamp[^\\0]              Ty Process\\[PID:TID]$"
            // },
            "basic" : {
                "pattern" : "^(?<timestamp>\\d{4}-\\d{2}-\\d{2} \\d{2}:\\d{2}:\\d{2}\\.\\d{3}) (?<level>\\w+) (?<process>[^[]+)\\[(?<pid>\\d+):(?<tid>\\d+)\\] \\[(?<subsystem>[^:]+):(?<category>[^\\]]+)\\] (?<body>[^\\0]*)$"
            }
        },
        "level-field" : "level",
        "level" : {
            "error" : "E",
            "warning" : "W"
        },
        "value" : {
            "component" : {
                "kind" : "string",
                "identifier" : true
            }
        },
        "sample" : [
            {
                "line" : "2019-06-10 16:42:12.271 Df mobiletimerd[51:42d] [com.apple.mobiletimer.logging:Agent] mobiletimerd starting...",
                "line" : "2019-06-10 16:42:12.274 Df mobiletimerd[51:477] [com.apple.mobiletimer.logging:Agent] <MTAgent: 0x155000f00> has launched",
                "line" : "2019-06-10 16:42:12.275 Df mobiletimerd[51:477] [com.apple.mobiletimer.logging:Alarms] Initializing <MTUserNotificationCenter: 0x153e15180>..."
            }
        ]
    }
}

Mike Laster

unread,
Jul 13, 2019, 4:54:15 PM7/13/19
to lnav
I'm making progress.  I get the log recognized if I strip out the header file that the log sometimes have.  I have an example where it is the first line and it breaks detection:

Sample log:
Timestamp               Ty Process[PID:TID]
2019-06-10 16:42:02.987 Ts [0:0] === system boot: ED2163F4-76FA-42E1-A097-2337A21ACC8F
2019-06-10 16:42:12.271 Df mobiletimerd[51:42d] [com.apple.mobiletimer.logging:Agent] mobiletimerd starting...
2019-06-10 16:42:12.274 Df mobiletimerd[51:477] [com.apple.mobiletimer.logging:Agent] <MTAgent: 0x155000f00> has launched
2019-06-10 16:42:12.275 Df mobiletimerd[51:477] [com.apple.mobiletimer.logging:Alarms] Initializing <MTUserNotificationCenter: 0x153e15180>...
2019-06-10 16:42:12.331 Df IOMFB_bics_daemon[42:44a] [com.apple.xpc.activity:Client] xpc_activity_register: com.apple.iomfb_bics_daemon, criteria: check-in
2019-06-10 16:42:12.345 Df IOMFB_bics_daemon[42:44a] [com.apple.xpc.activity:Client] _xpc_activity_register: com.apple.iomfb_bics_daemon, 0
2019-06-10 16:42:12.345 Df IOMFB_bics_daemon[42:44a] [com.apple.xpc.activity:Client] xpc_activity_set_criteria: com.apple.iomfb_bics_daemon, check-in
2019-06-10 16:42:12.353 Df IOMFB_bics_daemon[42:49c] [com.apple.xpc.activity:Client] xpc_activity_set_criteria, lower half: com.apple.iomfb_bics_daemon, check-in
2019-06-10 16:42:12.353 Df IOMFB_bics_daemon[42:49c] [com.apple.xpc.activity:Client] _xpc_activity_set_criteria: com.apple.iomfb_bics_daemon, check-in

How do I prevent the first header line from breaking my parse?

Timothy Stack

unread,
Jul 14, 2019, 12:02:30 AM7/14/19
to Mike Laster, lnav
On Sat, Jul 13, 2019 at 11:05 AM Mike Laster <mla...@gmail.com> wrote:
Are there any guides anywhere for how to go about creating a new format?

Sorry, I don't think there is really.  Many moons ago, Paul Wayper wrote a
little perl script to help you get started.  He sent a mail to this list awhile back:

 
I'm trying to add a format for the macOS .logarchive file.  I can convert it to plain text with "log show --style compact" and get logs that look like this:

2019-06-10 16:42:12.571 Df wcd[60:451] [com.apple.wcd:WC] Starting up                                                                                                              │

I have my JSON file created and it no longer has parse errors, but it isn't used either.  When I point Lnav at my log file it still parses as generic_log, not my custom "example_log" format.

A bug in the format file that is, unfortunately, not raised is that you repeated
the "line" property in the sample object instead of creating a new sample
object for each line.  The format has this:

        "sample" : [
            {
                "line" : "2019-06-10 16:42:12.271 Df mobiletimerd[51:42d] [com.apple.mobiletimer.logging:Agent] mobiletimerd starting...",
                "line" : "2019-06-10 16:42:12.274 Df mobiletimerd[51:477] [com.apple.mobiletimer.logging:Agent] <MTAgent: 0x155000f00> has launched",
                "line" : "2019-06-10 16:42:12.275 Df mobiletimerd[51:477] [com.apple.mobiletimer.logging:Alarms] Initializing <MTUserNotificationCenter: 0x153e15180>..."
            }
        ]

Instead of this:

        "sample" : [
            {
                "line" : "2019-06-10 16:42:12.271 Df mobiletimerd[51:42d] [com.apple.mobiletimer.logging:Agent] mobiletimerd starting..."
            },
            {
                "line" : "2019-06-10 16:42:12.274 Df mobiletimerd[51:477] [com.apple.mobiletimer.logging:Agent] <MTAgent: 0x155000f00> has launched"
            },
            {
                "line" : "2019-06-10 16:42:12.275 Df mobiletimerd[51:477] [com.apple.mobiletimer.logging:Alarms] Initializing <MTUserNotificationCenter: 0x153e15180>..."
            }
        ]

Once that is fixed, you'll see an error about the 'tid' in the first sample not matching because
the 'd' is not a numeral (the format has \d+ as the pattern).

If you add this other sample line:

    2019-06-10 16:42:02.987 Ts [0:0] === system boot: ED2163F4-76FA-42E1-A097-2337A21ACC8F

You'll get another error because the process name and subsystems parts are optional.

Once those are fixed, things seem to work.  I've attached the format file that I updated.

Also, the header line (Timestamp               Ty Process[PID:TID]) does not seem to be
an issue.  lnav treats it as a separate message with the same timestamp as the
following line.  I think the main issue was the format regex not matching the
'system boot' line.

thanks,

tim

--
You received this message because you are subscribed to the Google Groups "lnav" group.
To unsubscribe from this group and stop receiving emails from it, send an email to lnav+uns...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/lnav/61722254-a9a1-4a85-b47c-bf9fabe66d42%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.
laster.json
Reply all
Reply to author
Forward
0 new messages