security-growler icon indicating copy to clipboard operation
security-growler copied to clipboard

Stops working after a couple of hours (v2.2) [probably not after wake from sleep]

Open JayBrown opened this issue 8 years ago • 14 comments

This seems to be a bug. After wake from sleep Security Growler doesn't work, doesn't respond to anything. On my system (10.11.4) I need to select "Stop the background agent & Quit" from the menulet's menu. Funny thing is that the Security Growler menulet then actually doesn't quit; it keeps running, which would itself be another bug (a bug within a bug), and instead I get the notification that it's now watching, and then it works fine.

JayBrown avatar Apr 29 '16 10:04 JayBrown

It seems that this issue isn't restricted to wake-from-sleep. After a couple of hours Security Growler stopped working, even though I didn't put my Mac to sleep. So I guess the app needs some form of KeepAlive setting.

JayBrown avatar May 01 '16 14:05 JayBrown

Maybe it has to do with this error, which I received for the first time just now.

http://i.imgur.com/VYBwcqu.png

JayBrown avatar May 01 '16 14:05 JayBrown

Have not seen that error before, thanks for reporting! Would you mind posting the output of this command so I can see the full error message text.

grep ValueError < ~/Library/Logs/SecurityGrowler.log

pirate avatar May 01 '16 22:05 pirate

 ❯ grep ValueError < ~/Library/Logs/SecurityGrowler.log                                                                          [00:33:23]
[05/01 16:55] Stopped Watching Sources: ValueError
[05/01 16:55] Stopped Watching Sources: ValueError

JayBrown avatar May 01 '16 22:05 JayBrown

Whoops sorry, forgot to include surrounding lines that actually have the error info, can you run this and paste again:

grep --context=12 ValueError < ~/Library/Logs/SecurityGrowler.log

pirate avatar May 01 '16 22:05 pirate

 ❯ grep --context=12 ValueError < ~/Library/Logs/SecurityGrowler.log                                                             [00:44:56]
/var/log/system.log      : for sudo,ssh,portscan,ostiarius events
port 3689                : for connections events
port 3306                : for connections events
port 5900                : for vnc events
port 21                  : for connections events
port 585                 : for connections events
port 5432                : for connections events
port 445                 : for connections events
[05/01 16:53] ‼️ SUDO EVENT: USER [unknown]: /usr/bin/whoami
@ /
[05/01 16:53] ‼️ SUDO EVENT: USER [unknown]: /usr/bin/defaults read ~/Library/Preferences/USER_DEFINED_PREFERENCES USER_DEFINED_PREFS_KEY
@ /
[05/01 16:55] Stopped Watching Sources: ValueError
[05/01 16:45] Started Watching Sources:
/var/log/system.log      : for sudo,ssh,portscan,ostiarius events
port 3689                : for connections events
port 3306                : for connections events
port 5900                : for vnc events
port 21                  : for connections events
port 585                 : for connections events
port 5432                : for connections events
port 445                 : for connections events
[05/01 16:53] ‼️  SUDO EVENT: USER [unknown]: /usr/bin/whoami
@ /
[05/01 16:53] ‼️  SUDO EVENT: USER [unknown]: /usr/bin/defaults read ~/Library/Preferences/USER_DEFINED_PREFERENCES USER_DEFINED_PREFS_KEY
@ /
[05/01 16:55] Stopped Watching Sources: ValueError
[05/01 17:50] --------
[05/01 17:50] Started Watching Sources:
/var/log/system.log      : for sudo,ssh,portscan,ostiarius events
port 3689                : for connections events
port 3306                : for connections events
port 5900                : for vnc events
port 21                  : for connections events
port 585                 : for connections events
port 5432                : for connections events
port 445                 : for connections events
[05/01 19:53] ‼️ SUDO EVENT: USER [unknown]: /usr/bin/whoami
@ /

Note: the defaults read command is running with sudo, because the prefs file is accessed by another app that runs with root privileges, so the file is root access only. The whoami is just part of the routine.

JayBrown avatar May 01 '16 22:05 JayBrown

Hmm unfortunately that doesn't give any more valuable information. It's a little weird since a ValueError should log a stacktrace to the logfile before quitting.

    try:
        watch_sources()
    except BaseException as e:
        notify(type(e).__name__, 'Stopped Watching Sources')
        if isinstance(e, Exception):
            traceback.print_exc()

I'll change it to notify the traceback so it gets logged to all alert channels instead of just printing it to stdout with traceback.print_exc(). I don't have a lot of time tonight but I'll try and get around to it early next week, there are some other bugs I can fix and bundle with the next v2.3 release as well.

pirate avatar May 02 '16 00:05 pirate

Addendum: Last night I tested the sleep/wake thing again, but this time Security Growler kept working. (It was just a short sleep phase, i.e. 5 minutes.) This, coupled with the fact that Security Growler also just stopped working on its own without any sleep/wake thing, probably tells us that sleep/wake has nothing to do with it, and that it would rather be some kind of error that occurs after a couple of hours.

JayBrown avatar May 02 '16 08:05 JayBrown

I receive the same error @JayBrown with his imgur link, exactly, sometimes I get two back to back, again after a couple of hours of use. I am on 10.10.5, so it's not the new sandbox problm.

tyr:~/tmp benc$ uname -a Darwin tyr.local 14.5.0 Darwin Kernel Version 14.5.0: Mon Jan 11 18:48:35 PST 24

My python version is

Python 3.5.0 (v3.5.0:374f501f4567, Sep 12 2015, 11:00:19) [GCC 4.2.1 (Apple Inc. build 5666) (dot 3)] on darwin

I'll grep the log when it happens again. It might be useful to put the build/git-id in the settings file. I am using Security Growler v2.2 light mode. Using your .app bundle, didn't build from source.

BenjaminHCCarr avatar May 14 '16 15:05 BenjaminHCCarr

Added traceback notifications on error or quit (e3e4936), download the updated app here. Next time it has an error, copy paste the traceback and post it here, that'll let me find exactly what line the error is on.

pirate avatar May 17 '16 19:05 pirate

you asked for it ;) [05/25 19:05] Stopped Watching Sources: ValueError: Traceback (most recent call last): File "/Applications/Security Growler.app/Contents/Resources/growler.py", line 41, in <module> watch_sources() File "/Applications/Security Growler.app/Contents/Resources/growler.py", line 24, in watch_sources alert_type, title, content = parse_line(line, source) File "/Applications/Security Growler.app/Contents/Resources/parsers/__init__.py", line 39, in parse_line alert_type, title, content = parser.parse(line, source) File "/Applications/Security Growler.app/Contents/Resources/parsers/sudo.py", line 12, in parse pre, pwd, _, command = line.split(' ; ', 3) ValueError: need more than 1 value to unpack

diligiant avatar May 26 '16 08:05 diligiant

Awesome work @diligiant , thats exactly the stack trace I need to fix it. Looks like for the sudo parser I was naiive in assuming that a line always contains a ; semicolon. Will fix in next release. (Sorry about the delay guys, I've been really busy at work lately).

pirate avatar May 27 '16 17:05 pirate

thanks @pirate! that kind of thing happens, ping me when you roll a release, and I'll repackage homebrew.

BenjaminHCCarr avatar May 29 '16 17:05 BenjaminHCCarr

This looks to still be an issue in v2.3; showing a couple hours of (light) logging) so show that it works most of the time, but some sudo calls make it go sideways still.

[03/15 12:42] ‼️ SSH EVENT:  : from: 91.197.232.107 | Connection closed by 91.197.232.107 [pre...
[03/15 12:42] ‼️ SSH EVENT:  : from: 91.197.232.107 | Connection closed by 91.197.232.107 [pre...
[03/15 12:43] ‼️ SSH EVENT:  : from: 91.197.232.107 | Connection closed by 91.197.232.107 [pre...
[03/15 12:43] ‼️ SSH EVENT:  : from: 91.197.232.107 | Connection closed by 91.197.232.107 [pre...
[03/15 12:43] ‼️ SSH EVENT:  : from: 91.197.232.107 | Connection closed by 91.197.232.107 [pre...
[03/15 12:43] ‼️ SSH EVENT:  : from: 91.197.232.107 | Invalid user telecomadmin from 91.197.23...
[03/15 12:43] ‼️ SSH EVENT:  : from:  | input_userauth_request: invalid user tel...
[03/15 12:43] ‼️ SSH EVENT:  : from: 199.249.223.77 | Connection closed by 199.249.223.77 [pre...
[03/15 12:43] ‼️ SSH EVENT:  : from: 91.197.232.107 | Connection closed by 91.197.232.107 [pre...
[03/15 12:43] ‼️ SSH EVENT:  : from: 91.197.232.107 | Connection closed by 91.197.232.107 [pre...
[03/15 12:43] ‼️ SSH EVENT:  : from: 91.197.232.107 | Invalid user ubnt from 91.197.232.107...
[03/15 12:43] ‼️ SSH EVENT:  : from:  | input_userauth_request: invalid user ubn...
[03/15 12:43] ‼️ SSH EVENT:  : from: 91.197.232.107 | Connection closed by 91.197.232.107 [pre...
[03/15 14:32] ‼️ SSH EVENT:  : from: 202.215.132.129 | Invalid user admin from 202.215.132.129...
[03/15 14:32] ‼️ SSH EVENT:  : from:  | input_userauth_request: invalid user adm...
[03/15 14:32] ‼️ SSH EVENT: invalid: from: 202.215.132.129 | error: maximum authentication attempts e...
[03/15 14:32] ‼️ SSH EVENT:  : from:  | Disconnecting: Too many authentication f...
[03/15 14:34] ‼️ SSH EVENT:  : from: 175.143.14.138 | Invalid user support from 175.143.14.138...
[03/15 14:34] ‼️ SSH EVENT:  : from:  | input_userauth_request: invalid user sup...
[03/15 14:34] ‼️ SSH EVENT: invalid: from: 175.143.14.138 | error: maximum authentication attempts e...
[03/15 14:34] ‼️ SSH EVENT:  : from:  | Disconnecting: Too many authentication f...
 input_userauth_request: invalid user adm...
[03/15 12:42] ‼️  SSH EVENT:  : from: 91.197.232.107 | Connection closed by 91.197.232.107 [pre...
[03/15 12:42] ‼️  SSH EVENT:  : from: 91.197.232.107 | Invalid user cisco from 91.197.232.107...
[03/15 12:42] ‼️  SSH EVENT:  : from:  | input_userauth_request: invalid user cis...
[03/15 12:42] ‼️  SSH EVENT:  : from: 91.197.232.107 | Connection closed by 91.197.232.107 [pre...
[03/15 12:42] ‼️  SSH EVENT:  : from: 91.197.232.107 | Connection closed by 91.197.232.107 [pre...
[03/15 12:42] ‼️  SSH EVENT:  : from: 91.197.232.107 | Invalid user operator from 91.197.232.10...
[03/15 12:42] ‼️  SSH EVENT:  : from:  | input_userauth_request: invalid user ope...
[03/15 12:42] ‼️  SSH EVENT:  : from: 91.197.232.107 | Connection closed by 91.197.232.107 [pre...
[03/15 12:42] ‼️  SSH EVENT:  : from: 91.197.232.107 | Invalid user osmc from 91.197.232.107...
[03/15 12:42] ‼️  SSH EVENT:  : from:  | input_userauth_request: invalid user osm...
[03/15 12:42] ‼️  SSH EVENT:  : from: 91.197.232.107 | Connection closed by 91.197.232.107 [pre...
[03/15 12:42] ‼️  SSH EVENT:  : from: 91.197.232.107 | Invalid user osmc from 91.197.232.107...
[03/15 12:42] ‼️  SSH EVENT:  : from:  | input_userauth_request: invalid user osm...
[03/15 12:42] ‼️  SSH EVENT:  : from: 91.197.232.107 | Connection closed by 91.197.232.107 [pre...
[03/15 12:42] ‼️  SSH EVENT:  : from: 91.197.232.107 | Invalid user pi from 91.197.232.107...
[03/15 12:42] ‼️  SSH EVENT:  : from:  | input_userauth_request: invalid user pi ...
[03/15 12:42] ‼️  SSH EVENT:  : from: 91.197.232.107 | Connection closed by 91.197.232.107 [pre...
[03/15 12:42] ‼️  SSH EVENT:  : from: 91.197.232.107 | Connection closed by 91.197.232.107 [pre...
[03/15 12:43] ‼️  SSH EVENT:  : from: 91.197.232.107 | Connection closed by 91.197.232.107 [pre...
[03/15 12:43] ‼️  SSH EVENT:  : from: 91.197.232.107 | Connection closed by 91.197.232.107 [pre...
[03/15 12:43] ‼️  SSH EVENT:  : from: 91.197.232.107 | Connection closed by 91.197.232.107 [pre...
[03/15 12:43] ‼️  SSH EVENT:  : from: 91.197.232.107 | Invalid user telecomadmin from 91.197.23...
[03/15 12:43] ‼️  SSH EVENT:  : from:  | input_userauth_request: invalid user tel...
[03/15 12:43] ‼️  SSH EVENT:  : from: 199.249.223.77 | Connection closed by 199.249.223.77 [pre...
[03/15 12:43] ‼️  SSH EVENT:  : from: 91.197.232.107 | Connection closed by 91.197.232.107 [pre...
[03/15 12:43] ‼️  SSH EVENT:  : from: 91.197.232.107 | Connection closed by 91.197.232.107 [pre...
[03/15 12:43] ‼️  SSH EVENT:  : from: 91.197.232.107 | Invalid user ubnt from 91.197.232.107...
[03/15 12:43] ‼️  SSH EVENT:  : from:  | input_userauth_request: invalid user ubn...
[03/15 12:43] ‼️  SSH EVENT:  : from: 91.197.232.107 | Connection closed by 91.197.232.107 [pre...
[03/15 14:32] ‼️  SSH EVENT:  : from: 202.215.132.129 | Invalid user admin from 202.215.132.129...
[03/15 14:32] ‼️  SSH EVENT:  : from:  | input_userauth_request: invalid user adm...
[03/15 14:32] ‼️  SSH EVENT: invalid: from: 202.215.132.129 | error: maximum authentication attempts e...
[03/15 14:32] ‼️  SSH EVENT:  : from:  | Disconnecting: Too many authentication f...
[03/15 14:34] ‼️  SSH EVENT:  : from: 175.143.14.138 | Invalid user support from 175.143.14.138...
[03/15 14:34] ‼️  SSH EVENT:  : from:  | input_userauth_request: invalid user sup...
[03/15 14:34] ‼️  SSH EVENT: invalid: from: 175.143.14.138 | error: maximum authentication attempts e...
[03/15 14:34] ‼️  SSH EVENT:  : from:  | Disconnecting: Too many authentication f...
[03/15 15:09] Stopped Watching Sources: ValueError: Traceback (most recent call last):
  File "/Applications/Security Growler.app/Contents/Resources/growler.py", line 41, in <module>
    watch_sources()
  File "/Applications/Security Growler.app/Contents/Resources/growler.py", line 24, in watch_sources
    alert_type, title, content = parse_line(line, source)
  File "/Applications/Security Grow[03/15 15:09] Stopped Watching Sources: ValueError: Traceback (most recent call last):
  File "/Applications/Security Growler.app/Contents/Resources/growler.py", line 41, in <module>
    watch_sources()
  File "/Applications/Security Growler.app/Contents/Resources/growler.py", line 24, in watch_sources
    alert_type, title, content = parse_line(line, source)
  File "/Applications/Security Growler.app/Contents/Resources/parsers/__init__.py", line 39, in parse_line
    alert_type, title, content = parser.parse(line, source)
  File "/Applications/Security Growler.app/Contents/Resources/parsers/sudo.py", line 15, in parse
    pre, pwd, _, command = line.split(' ; ', 3)
ValueError: need more than 1 value to unpack

ler.app/Contents/Resources/parsers/__init__.py", line 39, in parse_line
    alert_type, title, content = parser.parse(line, source)
  File "/Applications/Security Growler.app/Contents/Resources/parsers/sudo.py", line 15, in parse
    pre, pwd, _, command = line.split(' ; ', 3)
ValueError: need more than 1 value to unpack

[03/15 15:11] --------
[03/15 15:11] Started Watching Sources: 
/var/log/system.log      : for sudo,ssh,portscan,ostiarius events
port 3689                : for connections events
port 3306                : for connections events
port 5900                : for vnc events
port 21                  : for connections events
port 585                 : for connections events
port 5432                : for connections events
port 445                 : for connections events

BenjaminHCCarr avatar Mar 15 '17 19:03 BenjaminHCCarr