tstack / lnav

Log file navigator
http://lnav.org
BSD 2-Clause "Simplified" License
7.99k stars 322 forks source link

[Bug?] /search frequent string flashes and green progress bar sweeping: continues #588

Open cw1nte opened 5 years ago

cw1nte commented 5 years ago

I have logs showing 64k lines 236k not shown. Did a search for my ip which reported found 24k times but with the flashing reversal and sweeping green affect that continues it was unclear what was going on. It even continued when I changed the search to something with 400 hits. It went away with a quit and restart, I should have tried and reported a force redraw but the other was quicker! I tried the same search again in the new session and the flash/sweeping was not seen.

I think in the "dubious session" I may also have had a lot of lines from one log source hidden. I could not spot any ip logging where it should have been but it did show up after the search for my ip, and then it was back interleaved where I was expecting it. The display of ip data just seemed to stop at a certain point in time... Possibly near when I was exploring naming regions of the log, no real evidence of that but earlier today was the first I tried that. I had also looked at the tree head filter detail to see which were catching what, 20 filters at present.

This is not a big issue to fix, just aiming to be a helpful note! Might be related to hidden lines!

cw1nte commented 5 years ago

Mmmm, I did see an oddity yesterday when looking at filtering

image

I think I had done a TAB, space to switch off the virginmedia filter, and return. I think the cyan sub-window was not full width. "Travel Ins etc" is the name of a mail box from the virginmedia data text, somehow!

tstack commented 5 years ago

Yes, hitting TAB when the cursor is at the start of the input box results in some odd completion behavior, thanks!

I've seen the search not stopping a few times, I'll take another look at that sometime soon as well.

jon-mcclung-sertainty commented 5 years ago

For me, the green bar always flashes after I make a search. I can't get it to stop with a Ctrl+R or by exiting and reopening the log or anything else.

tstack commented 5 years ago

What version are you using?

jon-mcclung-sertainty commented 5 years ago

0.8.4

It also causes the CPU usage to skyrocket.

dmig commented 5 years ago

Noticed this bug about half a year ago, subscribing. I always keep up2date git revision.

tstack commented 5 years ago

Hmm, I'm having trouble reproducing this consistently. If any of you folks can do it, can you run it in debug mode with -d /tmp/lnav.log and send the resulting file? It might give me a clue of what is going on.

cw1nte commented 5 years ago

I do not have a from start to bug method, I tend to have been using LNAV continuously and using a wide range of functionality for days and the bug has been rare. There have been a few crashes, not related AFAIK. Might they be useful if I can turn some up? I had a suspicion it might be to do with grep that overlap search patterns, with a wildcard,in some way. I know there area few grep versions out there with faults like that (had one instance 6months or so ago). I never dug into that thought :( Possibly start or end tags were implicated??

jon-mcclung-sertainty commented 5 years ago

I've emailed you a log file to check out.

tstack commented 5 years ago

I've pushed a couple of changes if anyone is able to update to the top-of-tree and see if there's an improvement.

cw1nte commented 5 years ago

Tried brew upgrade --HEAD lnav but get lnav HEAD-e001b49 already installed ?

tstack commented 5 years ago

@cw1nte Not sure what's up with brew, maybe uninstall and reinstall?

jon-mcclung-sertainty commented 5 years ago

I can't get a C++14 compiler on my machine, I'm using the .rpm

cw1nte commented 5 years ago

uninstall and reinstall worked fine. Very much liking the filter toggle... and "t" to swap type (was that new?) I think ^F deserves more advertising, maybe in the Filter bar prompt text: Press TAB to edit could be... TAB edit, ctrl-F toggle all OR at least show it when they have TABbed into filter editing.

I can see space is tight on info for filters... is there some way to combine Toggle active:SPC=current, ^F=all t:swap type i/o:

Would it be helpful for SPC to move to next/other filter? I'm unsure as sometimes I'm just looking at the effect on line counts so often I do off, #check, on, #check and sometimes I'm toggling a subset/group

duemir commented 5 years ago

I have a similar issue. The green progress bar is spinning, the message says 0 search results but the results are highlighted in the UI. n/N doesn't work. I installed from HEAD with brew to no effect.

Here is what I found in the debug log

2019-05-29T11:41:43.853 D textview_curses.cc:442 start search for: 'saml'
2019-05-29T11:41:43.896 E grep_proc.cc:311 bad line from child -- [?1049l
[?1l>
2019-05-29T11:41:43.896 E grep_proc.cc:311 bad line from child -- 
2019-05-29T11:41:43.896 E grep_proc.cc:311 bad line from child -- ==== GURU MEDITATION ====
2019-05-29T11:41:43.896 E grep_proc.cc:311 bad line from child -- Unfortunately, lnav has crashed, sorry for the inconvenience.
2019-05-29T11:41:43.896 E grep_proc.cc:311 bad line from child -- 
2019-05-29T11:41:43.896 E grep_proc.cc:311 bad line from child -- You can help improve lnav by sending the following file to lnav@googlegroups.com :
2019-05-29T11:41:43.896 E grep_proc.cc:311 bad line from child --   $HOME/.lnav/crash/crash-2019-05-29-11-41-43.20625.log
2019-05-29T11:41:43.896 E grep_proc.cc:311 bad line from child -- =========================

more details from the other log

2019-05-29T11:41:43.855 E lnav_log.cc:319 Received signal: 11
0   lnav                                0x000000010f07e592 _ZL7sigabrti + 110
1   libsystem_platform.dylib            0x00007fff7feadb5d _sigtramp + 29
2   ???                                 0x0000000000000000 0x0 + 0
3   lnav                                0x000000010f0ec48f _pcre_jit_exec + 331
4   lnav                                0x000000010f0c7eb1 pcre_exec + 545
5   lnav                                0x000000010f08f271 _ZNK6pcrepp5matchER12pcre_contextR10pcre_inputi + 99
6   lnav                                0x000000010ef29826 _ZN9grep_procI10strong_intIi19__vis_line_distinctEE10child_loopEv + 780
7   lnav                                0x000000010ef29393 _ZN9grep_procI10strong_intIi19__vis_line_distinctEE5startEv + 971
8   lnav                                0x000000010f04f9c6 _ZN15textview_curses14execute_searchERKNSt3__112basic_stringIcNS0_11char_traitsIcEENS0_9allocatorIcEEEE + 958
9   lnav                                0x000000010f0132e8 _ZL18rl_search_internalPvP15readline_cursesb + 382
10  lnav                                0x000000010f014ec3 _Z11rl_callbackPvP15readline_curses + 482
11  lnav                                0x000000010f01a420 _ZN15readline_curses14check_poll_setERKNSt3__16vectorI6pollfdNS0_9allocatorIS2_EEEE + 902
12  lnav                                0x000000010eef1f01 _ZL6looperv + 4725
13  lnav                                0x000000010eeefae9 main + 12510
14  libdyld.dylib                       0x00007fff7fcc83d5 start + 1
15  ???                                 0x0000000000000004 0x0 + 4
cw1nte commented 5 years ago

duemir's crash maybe has similarities to my recent #647? The curses routines again jumping to a zero location?...

2019-05-17T10:26:37.216 E lnav_log.cc:325 Received signal: 11 0 lnav 0x00000001082f4205 _ZL7sigabrti + 108 1 libsystem_platform.dylib 0x00007fff82a1a52a _sigtramp + 26 2 ??? 0x0000000000000000 0x0 + 0 3 lnav 0x000000010818011d _ZN15listview_curses9do_updateEv + 821 4 lnav 0x00000001082c491e _ZN15textview_curses9do_updateEv + 14 5 lnav 0x000000010813a6fd _ZN10view_stackI15textview_cursesE9do_updateEv + 63

@duemir: Any notes on your build environment? I was building on MacOS 10.11.6 El Cap, which brew warns may not be fully supported. I think my ncurses library was also updated as a dependant during the build...

==> Caveats ncurses is keg-only, which means it was not symlinked into /usr/local, because macOS already provides this software and installing another version in parallel can cause all kinds of trouble.

tstack commented 5 years ago

@duemir Sorry, this is due to a bug in the version of pcre in homebrew, see #638

cw1nte commented 5 years ago

Just brew'd HEAD-b5c6ed6 version id 0.8.5 It seems stable on Mojave looking at (in Mojave the no longer much used) system.log: FINE no green bar flashing. If I pipe from (unified logging) with : log stream|lnav where I had 23 or so filters in last session then I get the green flashing very fast for a filter that is actually switched off, but is last in the list, and high cpu even when there is no data arriving. If I reset session (^R) then no filter, no flashing green & cpu drops down.

When I looked at the screen after typing this it was flashing again, flashing message quotes the /search_txt (which was the same as my last, unused, filter). Clearing search by /\<nothing> stops the flashing.

Adding 3 or 4 filters, all active filter_outs, is still fine. Searching for a string I can see (locationd) reported 0 hits but was highlighting the 20 or so in window. Search continues to highlight but report none fine as I scrolled up screen, then it started green flashing: maybe data started arriving? Clearing search with new / removed flashing green message...

tiann commented 5 years ago

I have the same problem, where can i found the HEAD build ? (I am using CentOS)

And is there a daily build for Lnav?