pirate / security-growler

:satellite: A Mac menubar app that notifies you whenever SSH, VNC, sudo, or other auth events occur.
https://sweeting.me/security-growler
858 stars 57 forks source link

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

Open JayBrown opened 8 years ago

JayBrown commented 8 years ago

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 commented 8 years ago

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 commented 8 years ago

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

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

pirate commented 8 years ago

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

JayBrown commented 8 years ago
 ❯ 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
pirate commented 8 years ago

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

JayBrown commented 8 years ago
 ❯ 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.

pirate commented 8 years ago

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.

JayBrown commented 8 years ago

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.

BenjaminHCCarr commented 8 years ago

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.

pirate commented 8 years ago

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.

diligiant commented 8 years ago

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

pirate commented 8 years ago

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).

BenjaminHCCarr commented 8 years ago

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

BenjaminHCCarr commented 7 years ago

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