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.

Sign up for GitHub

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

Jump to bottom

premature channel closure prevents sending SummaryInfo #250

Open
jtmoon79 opened this issue Mar 17, 2024 · 0 comments
Open

premature channel closure prevents sending SummaryInfo #250

jtmoon79 opened this issue Mar 17, 2024 · 0 comments
Labels
bug Something isn't working P1 important

Comments

@jtmoon79
Copy link
Owner

jtmoon79 commented Mar 17, 2024 •
edited
Loading

A fix for #241 introduces a new problem where summary information specific to the file processing thread can never be sent to the main thread.
In the fix for #241, the main thread may see an error printing. If it does, then the main thread immediately closes the channel for the associated file. The file-processing thread then sees that the channel is closed and so it returns without having sent Summary information. Currently, there is no quick fix for this.

To Reproduce

Run and pipe to head and pass --summary

$ ./target/release/s4 ./logs/Debian11/messages --summary | head -n1
Oct 10 23:07:16 debian-s-1vcpu-1gb-nyc1-01 kernel: [    0.6924] Linux version 5.10.0-11-amd64 ([email protected]) (gcc-10 (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2) #1 SMP Debian 5.10.92-1 (2022-01-18)

Files:

File: ./logs/Debian11/messages
  About:
      realpath       : /home/user/super-speedy-syslog-searcher/logs/Debian11/messages
      Modified Time  : 2022-10-11T00:02:36-07:00 (2022-10-11 07:02:36 +00:00)
      filetype       : TEXT
      logmessagetype : syslog lines
      MIME guess     : MimeGuess([])
  Processed: None


Program Summary:

Paths considered      : 1
Paths not processed   : 0
Files processed       : 1
Files printed         : 1
Printed bytes         : 1012
Printed lines         : 7
Printed syslines      : 7
Printed evtx events   : 0
Printed fixedstruct   : 0
Printed journal events: 0
Regex compiled        : 127
Datetime filter -a    :
Datetime printed first: 2022-10-10T23:07:16-07:00 (2022-10-11 06:07:16 +00:00)
Datetime printed last : 2022-10-10T23:07:16-07:00 (2022-10-11 06:07:16 +00:00)
Datetime filter -b    :
Datetime Now          : 2024-03-17T14:40:37-07:00 (2024-03-17 21:40:37 +00:00)
Channel Receive ok    : 8
Channel Receive err   : 0

Here is the same run without | head -n1

$ ./target/release/s4 ./logs/Debian11/messages --summary
Oct 10 23:07:16 debian-s-1vcpu-1gb-nyc1-01 kernel: [    0.6924] Linux version 5.10.0-11-amd64 ([email protected]) (gcc-10 (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2) #1 SMP Debian 5.10.92-1 (2022-01-18)
Oct 10 23:07:16 debian-s-1vcpu-1gb-nyc1-01 kernel: [    0.6924] Command line: BOOT_IMAGE=/boot/vmlinuz-5.10.0-11-amd64 root=UUID=00000000-1111-2222-adf0-012345678911 ro console=tty0 console=ttyS0,6924 earlyprintk=ttyS0,6924 consoleblank=0 net.ifnames=0 biosdevname=0
Oct 10 23:07:16 debian-s-1vcpu-1gb-nyc1-01 kernel: [    0.6924] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
Oct 10 23:07:16 debian-s-1vcpu-1gb-nyc1-01 kernel: [    0.6924] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
Oct 10 23:07:16 debian-s-1vcpu-1gb-nyc1-01 kernel: [    0.6924] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
Oct 10 23:07:16 debian-s-1vcpu-1gb-nyc1-01 kernel: [    0.6924] x86/fpu: xstate_offset[2]:  576, xstate_sizes[2]:  256
Oct 10 23:07:16 debian-s-1vcpu-1gb-nyc1-01 kernel: [    0.6924] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format.
Oct 10 23:07:16 debian-s-1vcpu-1gb-nyc1-01 kernel: [    0.6924] BIOS-provided physical RAM map:
Oct 10 23:07:16 debian-s-1vcpu-1gb-nyc1-01 kernel: [    0.6924] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
Oct 10 23:07:16 debian-s-1vcpu-1gb-nyc1-01 kernel: [    0.6924] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved

Oct 11 00:02:36 debian-s-1vcpu-1gb-nyc1-01 kernel: [    4.6924] audit: type=1400 audit(0123456789.592:5): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/bin/man" pid=293 comm="apparmor_parser"
Oct 11 00:02:36 debian-s-1vcpu-1gb-nyc1-01 kernel: [    4.6924] audit: type=1400 audit(0123456789.592:6): apparmor="STATUS" operation="profile_load" profile="unconfined" name="man_filter" pid=293 comm="apparmor_parser"
Oct 11 00:02:36 debian-s-1vcpu-1gb-nyc1-01 kernel: [    4.6924] audit: type=1400 audit(0123456789.592:7): apparmor="STATUS" operation="profile_load" profile="unconfined" name="man_groff" pid=293 comm="apparmor_parser"
Oct 11 00:02:36 debian-s-1vcpu-1gb-nyc1-01 kernel: [    4.6924] audit: type=1400 audit(0123456789.620:8): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/sbin/chronyd" pid=296 comm="apparmor_parser"
Oct 11 00:02:36 debian-s-1vcpu-1gb-nyc1-01 kernel: [    4.6924] qxl 0000:00:02.0: [drm] fb0: qxldrmfb frame buffer device
Oct 11 00:02:36 debian-s-1vcpu-1gb-nyc1-01 kernel: [    4.6924] audit: type=1400 audit(0123456789.676:9): apparmor="STATUS" operation="profile_load" profile="unconfined" name="tcpdump" pid=300 comm="apparmor_parser"
Oct 11 00:02:36 debian-s-1vcpu-1gb-nyc1-01 DigitalOcean: writing resolvers  to /etc/systemd/resolved.conf.d/DigitalOcean.conf
Oct 11 00:02:36 debian-s-1vcpu-1gb-nyc1-01 DigitalOcean: adding random seed to /dev/urandom
Oct 11 00:02:36 debian-s-1vcpu-1gb-nyc1-01 rsyslogd: imuxsock: Acquired UNIX socket '/run/systemd/journal/syslog' (fd 3) from systemd.  [v8.2102.0]
Oct 11 00:02:36 debian-s-1vcpu-1gb-nyc1-01 rsyslogd: [origin software="rsyslogd" swVersion="8.2102.0" x-pid="562" x-info="https://www.rsyslog.com"] start

Files:

File: ./logs/Debian11/messages
  About:
      realpath       : /home/user/super-speedy-syslog-searcher/logs/Debian11/messages
      Modified Time  : 2022-10-11T00:02:36-07:00 (2022-10-11 07:02:36 +00:00)
      filetype       : TEXT
      logmessagetype : syslog lines
      MIME guess     : MimeGuess([])
  Printed:
      bytes         : 3258
      lines         : 21
      syslines      : 20
      datetime first: 2022-10-10T23:07:16-07:00 (2022-10-11 06:07:16 +00:00)
      datetime last : 2022-10-11T00:02:36-07:00 (2022-10-11 07:02:36 +00:00)
  Processed:
      file size     : 3258 (0xCBA) (bytes)
      bytes         : 3258 (0xCBA)
      bytes total   : 3258 (0xCBA)
      block size    : 65535 (0xFFFF)
      blocks        : 1
      blocks total  : 1
      blocks high   : 1
      lines         : 21
      lines high    : 21
      syslines      : 21
      syslines high : 20
      datetime first: 2022-10-10T23:07:16-07:00 (2022-10-11 06:07:16 +00:00)
      datetime last : 2022-10-11T00:02:36-07:00 (2022-10-11 07:02:36 +00:00)
  Parsers:
      @[33] uses 22 DateTimeParseInstr: { regex_pattern: "^(?P<month>january|J…", line: 3119, range_regex: 0..22, cgn_first: "month", cgn_last: "second", : DTFSSet: { year: _fill, month: B, day: _e_or_d, hour: H, second: S, fractional: _none, tz: _fill, year?: false, tz?: false, pattern: "%Y%m%dT%H%M%S%:z" } }
                   datetime format missing year; estimated year of last sysline 2022
  Processing Stores:
      storage: BlockReader::read_block() blocks                    : hit  0, miss  1,  0.0%, put  1 (rereads 0)
      caching: BlockReader::read_block() LRU cache                 : hit 23, miss  1, 95.8%, put  1
      storage: LineReader::find_line() lines                       : hit 19, miss 43, 30.6%
      caching: LineReader::find_line() LRU cache                   : hit  2, miss 43,  4.4%, put 42
      copying: SyslineReader::get_boxptrs()                        : sgl 55, dbl   0, mult  0
      storage: SyslineReader::find_sysline() syslines              : hit  0, miss 21,  0.0%
      caching: SyslineReader::find_sysline() syslines_by_range_map : hit 20, miss 21, 48.8%, put 21
      caching: SyslineReader::find_sysline() LRU cache             : hit  0, miss 41,  0.0%, put 41
      caching: SyslineReader::parse_datetime_in_line() LRU cache   : hit 19, miss 24, 44.2%, put  0
      optimize:SyslineReader::ezcheck12                            : hit  0, miss  0,  0.0%, largest skipped 0
      optimize:SyslineReader::ezcheckd2                            : hit  0, miss 25,  0.0%, largest skipped 0
      optimize:SyslineReader::ezcheck12d2                          : hit  0, miss 30,  0.0%, largest skipped 0
      process: regex captures attempted                            : 55
  Processing Drops:
      streaming: BlockReader::drop_block()          : Ok 0, Err 0
      streaming: LineReader::drop_line()      : Ok 0, Err 0
      streaming: SyslineReader::drop_sysline(): Ok 0, Err 0


Program Summary:

Paths considered      : 1
Paths not processed   : 0
Files processed       : 1
Files printed         : 1
Printed bytes         : 3259
Printed lines         : 21
Printed syslines      : 20
Printed evtx events   : 0
Printed fixedstruct   : 0
Printed journal events: 0
Regex compiled        : 127
Datetime filter -a    :
Datetime printed first: 2022-10-10T23:07:16-07:00 (2022-10-11 06:07:16 +00:00)
Datetime printed last : 2022-10-11T00:02:36-07:00 (2022-10-11 07:02:36 +00:00)
Datetime filter -b    :
Datetime Now          : 2024-03-17T14:41:31-07:00 (2024-03-17 21:41:31 +00:00)
Channel Receive ok    : 22
Channel Receive err   : 0
@jtmoon79 jtmoon79 added bug Something isn't working P1 important labels Mar 17, 2024
jtmoon79 added a commit that referenced this issue Mar 17, 2024
@jtmoon79
bin.rs do not print after printing error
157d54a 
Do not print after printing error except in debug builds.
This makes for better cooperationg when piped to other programs
like `head` which may suddenly close the pipe.

This does introduce a new Issue #250.

Issue #241
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working P1 important
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@jtmoon79