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

Cant filter on rotated logs (filter-in filter-out), searching works fine. #654

Open
jmj-uy opened this issue Jun 3, 2019 · 9 comments
Open

Comments

@jmj-uy
Copy link

jmj-uy commented Jun 3, 2019

Hi! (Version: lnav 0.8.5)
Im using lnav to parse Apache logs, and it usually works without issues. But recently looking through some rotated Apache logs, i found that although I can search withing lnav, all filtering stoped working for some reason.
After looking into the log files, I found that if the log file starts with a "log rotation stamp", the filter-in and filter-out functions wont work.

To reproduce, add as the first line in an Apache log the following line:
May 31 00:00:00 hostname newsyslog[11111]: logfile turned over

Also, this only happens if that is the First line only, if you insert it in the middle of the log file, lnav works as usual.

If you remove the last digit in the time stamp, filtering will work as usual:
May 31 00:00:0 hostname newsyslog[11111]: logfile turned over

A similar issue is reproduced, but not in the whole log file, but only on that line if you add a ":" before the URI:
192.168.1.2 - - [31/May/2019:17:48:39 -0300] :"GET /path/resource.php HTTP/1.1" 200 254

As a side note, in version 0.8.2; the a similar issue happened, and started working again if i remove the last digit in the timestamp or if the last ":" is removed:
May 31 00:00:00 hostname newsyslog[11111] logfile turned over
May 31 00:00:0 hostname newsyslog[11111]: logfile turned over

Maybe the 2 versions behavior helps you find the issue.

@cw1nte
Copy link

cw1nte commented Jun 5, 2019

Not sure if related, but rather than add a new issue report...
I am filtering out log entries (from multiple file sources) entries that are actually only in one log file source, they have the string QQ and that is what I filter-out. It is working and removing thousands from the display BUT it does not get all of them, 7 have slipped through in last 2 hours out of several thousand I'd guess. There is no obvious special text or strings that would seem to distinguish them from the adjacent lines that are filtered out.
/QQ search does count the lines that slip through (7 as I write)
Maybe it is a timing thing?
IF I disable the filter and re-enable it then all the QQ lines are removed from display, but thereafter a few more will slowly arrive...
This happens regardless if I ^F then ^F cycle all filters or just TAB-SPC off the one and then TAB back, then re-enable it.
The /QQ search now finds no hits, until the next arrives.
I do have -d logging running if there is anything you'd like me to look for (I must admit I've let it grow to 56Mb at present, mostly file will be 99%+ full of
curl_looper.cc:127 no requests in progress, waiting 1000 ms for new ones
(which as mentioned elsewhere would be useful to be able to disable somehow with an env variable or -d level parameter)
This is 0.8.4, lnav-31c4407 as I have BPT-5 missing dylib symbol problem with 0.8.5 arising when brew builds on El Capitan MacOS:

  				Dyld Error Message:
  				  Symbol not found: _sqlite3_value_subtype
  				  Referenced from: /Volumes/VOLUME/*/lnav
  				  Expected in: /usr/lib/libsqlite3.dylib

The log with QQ in is not rotated, others are. The loss of filter-out is not at times that any of my log files are being rotated, there is at least one gz log history file open (but not, of course, getting updates).
Hope this helps!

@tstack
Copy link
Owner

tstack commented Jun 5, 2019

@jmj-uy In your case, what is the format of the file you're looking at? Is it apache logs wrapped in syslog? If not, I'm not clear on how a syslog message is getting into the apache-formatted logs.

@cw1nte Ah, sorry, I thought I figured out the last of the filtering bugs. I'll dive in again.

@jmj-uy
Copy link
Author

jmj-uy commented Jun 5, 2019

@tstack the format is Apache log. But the utility used for log rotation is newsyslog (its a freeBSD system), so logs starts with a newsyslog timestamp and reason of the log rotation (in this case is only by a cron job, not log size or other reason).
From the openBSD newsyslog man (https://man.openbsd.org/newsyslog.8):

ASCII message which newsyslog inserts to indicate the fact that the logs have been turned over

Similar on the freeBSD newsyslog man (https://www.freebsd.org/cgi/man.cgi?query=newsyslog.conf&sektion=5&manpath=freebsd-release-ports), under the flags section; the flag 'B' states if the file is a binary and not inserting the "turn over" message.

I dont know if this qualifies as a 'wrapped in syslog'... But that's de reason why those lines are in the log file.

@cw1nte
Copy link

cw1nte commented Jun 6, 2019

Just reset my "QQ" filter, had to ^F all off and ^F all on as TAB>off>TAB then TAB>on>TAB still left the same batches of QQ lines in display.
Maybe I had it wrong before or maybe it depends on something else so it appears inconsistent...
(NB I have 29 filters active, maybe this is relevant)

@tstack
Copy link
Owner

tstack commented Jun 19, 2019

@jmj-uy lnav can only support one file format per file. So, if the first line is a syslog message, the rest of the file will be parsed as if it were syslog. In this case, the rollover message is confusing lnav and resulting in the apache log messages not being recognized. Are you able to use the 'B' option to disable the rollover message for these files?

@cw1nte
Copy link

cw1nte commented Sep 25, 2020

Just downloaded latest zip for macOS, lnav-0.9.0-os-x.zip

But run crashes, however this is the same as I have had for a long time and I can still only run a rather old version of lnav 0.8.4 built here with brew over 18 months ago (I am running El Cap 10.11.6)...
Crash log excerpt:
Exception Codes: 0x0000000000000002, 0x0000000000000000
Exception Note: EXC_CORPSE_NOTIFY

Dyld Error Message:
Symbol not found: _sqlite3_value_subtype
Referenced from: /Volumes/VOLUME/*/lnav
Expected in: /usr/lib/libsqlite3.dylib

Thread 0 Crashed:: Dispatch queue: com.apple.main-thread

$ls -al /usr/lib/libsqlite3.dylib
-rwxr-xr-x 1 root wheel 3888048 12 Mar 2016 /usr/lib/libsqlite3.dylib

Note this is as per my report above June 5, 2019

@cw1nte
Copy link

cw1nte commented Sep 25, 2020

further detail on that library
otool -L /usr/lib/libsqlite3.dylib
/usr/lib/libsqlite3.dylib:
/usr/lib/libsqlite3.dylib (compatibility version 9.0.0, current version 216.4.0)
/usr/lib/libSystem.B.dylib (compatibility version 1.0.0, current version 1226.10.1)

@tstack
Copy link
Owner

tstack commented Sep 25, 2020

@cw1nte It looks like I didn't do the OS X build right, I'll redo it to make sure things are statically linked this morning.

@tstack
Copy link
Owner

tstack commented Sep 25, 2020

@cw1nte Can you try the following build, it should have more of the libraries statically linked:

https://github.com/tstack/lnav/releases/download/v0.9.0/lnav-0.9.0a-os-x.zip

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

No branches or pull requests

3 participants