Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Is it possible to define a log format without timestamp? #728

Open
jianhuiz opened this issue Apr 28, 2020 · 7 comments
Open

Is it possible to define a log format without timestamp? #728

jianhuiz opened this issue Apr 28, 2020 · 7 comments
Labels
enhancement Feature Request

Comments

@jianhuiz
Copy link

I'm looking into use lnav to color and filter the dumped call stacks, however it appears that timestamp is required for a log pattern, is there a way to get around this?

error:quickstack_log:timestamp field 'timestamp' not found in pattern -- ^Thread (?\d+) (LWP \d+), (?<thread_name>.):\n(?#\d+ .\n)*

@tstack
Copy link
Owner

tstack commented Apr 30, 2020

Sorry, no, lnav requires a timestamp for logs at the moment. Can you give some sample logs to help me understand what you're trying to do?

The timestamp is used to sort/collate log messages from different files into a single view. It's possible to view text files in lnav, but the functionality available for logs doesn't really carry over.

@jianhuiz
Copy link
Author

Just gdb backtrace per thread, so I can easily filter the stack of interesting threads.
If there has to be a timestamp, maybe I can use thread id to trick it? Can I define a custom timestamp format, or rewrite the value to something reasonable?

`
Thread 525 (LWP 1006), GlobalIOThreadP:
#1 0x00007fea70de5025 in epoll_pwait () from /usr/local/lib/libc-2.26.so
#2 0x000000000491a57b in event_base_loop () from /usr/local/libevent/1.4.14b_hphp/src/libevent-1.4.14b-stable/event.c:524
#3 0x00000000042e7cb0 in folly::EventBase::loopBody () from ./folly/io/async/EventBase.cpp:104

Thread 523 (LWP 1004), GlobalIOThreadP:
#1 0x00007fea70de5025 in epoll_pwait () from /usr/local/lib/libc-2.26.so
#2 0x000000000491a57b in event_base_loop () from /usr/local/libevent/1.4.14b_hphp/src/libevent-1.4.14b-stable/event.c:524
#3 0x00000000042e7cb0 in folly::EventBase::loopBody () from ./folly/io/async/EventBase.cpp:104
`

@tstack tstack added the enhancement Feature Request label Dec 9, 2020
@byron-hawkins
Copy link

I'd like to use lnav for the debug logs generated by my algorithm prototype, where timestamps are totally meaningless and in principle should be strictly avoided. The log entries are sequential, so only the order of log entries is significant. Many features of lnav still apply to this use case, even though there is no correlation of logs from multiple sources. For now I will simply add a hidden timestamp, but it will bog down my prototype when a log gets larger than a few GB.

As a simple implementation of a format with no timestamp, I would suggest that lnav assign an artificial integer timestamp to each entry. If the user tries to correlate multiple files, there will be a false interleaving line-by-line. This could be avoided with a (large) offset per file (i.e., file 2 starts at 1000000), or lnav could simply refulse to correlate files multiple files where the format has no timestamp.

@njokipal
Copy link

njokipal commented Nov 23, 2021

I have another log format that isn't usable with lnav as there are not timestamps on every entry:

Google Cloud emulator logs (firebase-debug.log) entries like

[debug] [2021-11-23T08:52:15.005Z] ----------------------------------------------------------------------
[debug] [2021-11-23T08:52:15.007Z] Command:       .../.nvm/versions/node/v14.17.6/bin/node .../.nvm/versions/node/v14.17.6/bin/firebase emulators:start --only functions,pubsub
[debug] [2021-11-23T08:52:15.007Z] CLI Version:   9.22.0
[debug] [2021-11-23T08:52:15.007Z] Platform:      linux
[debug] [2021-11-23T08:52:15.008Z] Node Version:  v14.17.6
[debug] [2021-11-23T08:52:15.008Z] Time:          Tue Nov 23 2021 10:52:15 GMT+0200 (Eastern European Standard Time)
[debug] [2021-11-23T08:52:15.008Z] ----------------------------------------------------------------------
[debug] 
[debug] [2021-11-23T08:52:15.061Z] > command requires scopes: ["email","openid","https://www.googleapis.com/auth/cloudplatformprojects.readonly","https://www.googleapis.com/auth/firebase","https://www.googleapis.com/auth/cloud-platform"]
[debug] [2021-11-23T08:52:15.061Z] > authorizing via signed-in user (...)
[info] i  emulators: Starting emulators: functions, pubsub {"metadata":{"emulator":{"name":"hub"},"message":"Starting emulators: functions, pubsub"}}
[debug] [2021-11-23T08:52:15.071Z] [hub] writing locator at /tmp/hub-checkout-dev-f7989.json
[warn] ⚠  functions: The following emulators are not running, calls to these services from the Functions emulator will affect production: auth, firestore, database, hosting, storage {"metadata":{"emulator":{"name":"functions"},"message":"The following emulators are not running, calls to these services from the Functions emulator will affect production: \u001b[1mauth, firestore, database, hosting, storage\u001b[22m"}}
[info] ✔  functions: Using node@14 from host. {"metadata":{"emulator":{"name":"functions"},"message":"Using node@14 from host."}}

Where most of the service log entries have a timestamp, for the Nodejs service's stdout writes appear with level, but no timestamps. The logs are ordered by timestamps, so some sort of pseudo-timestamp would be enough to obtain a reasonable ordering for my needs

@sellaziz
Copy link

Hi, thanks for the lnav project, it is super usefull.
I am also interested in a mode without timestamps for custom patterns.

@ewan-chalmers
Copy link

ewan-chalmers commented Sep 6, 2023

I found this limitation while trying to define a log format for Ansible playbook output

"pattern": "(?P<body>(?P<first>^[^\\s][ \\S]+\\n)(?P<others>  [\\S ]*\\n)*(})?)"

I tried just shoving in an empty timestamp group. Unsurprisingly that didn't work ;)

 "pattern": "(?P<timestamp>[\\S]{0})(?P<body>(?P<first>^[^\\s][ \\S]+\\n)(?P<others>  [\\S ]*\\n)*(})?)"
  • The output is multiline
  • First line starts with a character
  • In examples I'm using, subsequent lines are indented, unless JSON is dumped in which case the final line is the closing "}"

Truncated example:

Executing playbook check_stuff.yaml

- localhost on hosts: localhost -
Gathering Facts...
  localhost ok
Check if cache is present...
  localhost ok
Read Cache...
Is present...
Set namespace...
  localhost ok
Get Custom Resource...
  localhost ok
Get service status foo...
  localhost ok | msg: OK (448 bytes)
Show output for foo...
  localhost ok: {
    "changed": false,
    "msg": {
        "items": [
            {
                "message": "bar is healthy",
                "name": "bar",
                "statusCode": 200
            }
        ]
    }
}
Listing failed services...
  localhost failed | msg: 
WARN: The following services are reporting failures:
==> [FOO]
  Ran out of hosts!

- Play recap -
  localhost                  : ok=87   changed=3    unreachable=0    failed=1    rescued=1    ignored=3   
Error: command terminated with exit code 2

@tstack
Copy link
Owner

tstack commented Sep 6, 2023

For Ansible, it looks like there's a profile_tasks plugin that will add timestamps. So, you can build a format file for that.

You could also try the new :sh command available in a nightly build. That will execute the command and capture the output and record the timestamps internally. But, the captured output will not be integrated into the LOG view.

Can I ask what you're looking to do with the Ansible output within lnav?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
enhancement Feature Request
Projects
None yet
Development

No branches or pull requests

6 participants