To Generation D:
This was the setup at time this issue was observed: secast-1.0.1.0-x86_64-ub12 on Ubuntu 12.04.4 Server LTS with Asterisk 11.10.2.
The following events were captured and observed in the /var/log/secast after leaving seacast (build secast-1.0.1.0-x86_64-ub12) running:
Sun Jun 22 14:22:45 2014, 00001403, D, Asterisk, IP '' added to watch list
Sun Jun 22 14:22:45 2014, 00000510, I, Asterisk, Detected potential intrustion attempt by username '%40102' at IP '' using protocol 'SIP' through security log '/var/log/asterisk/messages'
Sun Jun 22 14:23:05 2014, 00001402, D, Asterisk, IP '' on IP watch list with 2 potential intrusion attempts
Sun Jun 22 14:23:05 2014, 00000510, I, Asterisk, Detected potential intrustion attempt by username '%40102' at IP '' using protocol 'SIP' through security log '/var/log/asterisk/messages'
Sun Jun 22 14:23:07 2014, 00001402, D, Asterisk, IP '' on IP watch list with 3 potential intrusion attempts
Sun Jun 22 14:23:07 2014, 00000510, I, Asterisk, Detected potential intrustion attempt by username '%40' at IP '' using protocol 'SIP' through security log '/var/log/asterisk/messages'
Sun Jun 22 14:23:27 2014, 00001402, D, Asterisk, IP '' on IP watch list with 4 potential intrusion attempts
Sun Jun 22 14:23:27 2014, 00000510, S, Asterisk, Detected excessive intrustion attempts by username '%40' at IP '' using protocol 'SIP' through security log '/var/log/asterisk/messages'. Requesting ban.
Sun Jun 22 14:23:27 2014, 00000902, D, ThreatInfo, Adding IP address to banned IP list
Sun Jun 22 14:23:27 2014, 00000608, S, EventQueue, Banning detected IP as managed
Sun Jun 22 14:23:27 2014, 00000710, E, SystemCommand, Failed to add rule to iptables chain. Run result 0; exitcode 2
:
:
Sun Jun 22 14:24:08 2014, 00001402, D, Asterisk, IP '' on IP watch list with 5 potential intrusion attempts
Sun Jun 22 14:24:08 2014, 00000510, S, Asterisk, Detected excessive intrustion attempts by username '%40' at IP '' using protocol 'SIP' through security log '/var/log/asterisk/messages'. Requesting ban.
Sun Jun 22 14:24:08 2014, 00000900, D, ThreatInfo, Ignoring attempt to add duplicate IP to banned IP list
Sun Jun 22 14:25:28 2014, 00001402, D, Asterisk, IP '' on IP watch list with 6 potential intrusion attempts
Sun Jun 22 14:25:28 2014, 00000510, S, Asterisk, Detected excessive intrustion attempts by username '%40' at IP '' using protocol 'SIP' through security log '/var/log/asterisk/messages'. Requesting ban.
Sun Jun 22 14:25:28 2014, 00000900, D, ThreatInfo, Ignoring attempt to add duplicate IP to banned IP list
Sun Jun 22 14:35:36 2014, 00001405, D, Asterisk, IP '' removed from IP watch list due to expiration
Note that the reference to IP '', where no actual IP address is shown. It seems that this empty IP reference is causing failure when attempting to add the rule to the iptables chain. Also, attempts to add this to the database seem to be failing (lines omitted above).
Perhaps this indicates that the case of IP '' should be detected to avoid invalid attempts to call upon iptables and the database.
The following are the lines from /var/log/asterisk/messages (with our IP address replaced with IP_REMOVED) that correspond to the events above:
[Jun 22 14:22:45] NOTICE[7420] chan_sip.c: Registration from '<sip:%40102@IP_REMOVED>' failed for '176.58.69.112:14398' - Wrong password
[Jun 22 14:22:48] NOTICE[7420][C-0000005a] chan_sip.c: Failed to authenticate device <sip:%40102@IP_REMOVED>;tag=17280b03
[Jun 22 14:22:55] NOTICE[7420][C-0000005b] chan_sip.c: Failed to authenticate device <sip:%40102@IP_REMOVED>;tag=394a4856
[Jun 22 14:23:01] NOTICE[7420][C-0000005c] chan_sip.c: Failed to authenticate device <sip:%40102@IP_REMOVED>;tag=022a0438
[Jun 22 14:23:05] NOTICE[7420] chan_sip.c: Registration from '<sip:%40102@IP_REMOVED>' failed for '176.58.69.112:14398' - Wrong password
[Jun 22 14:23:07] NOTICE[7420] chan_sip.c: Registration from '<sip:%40@IP_REMOVED>' failed for '176.58.69.112:14398' - Wrong password
[Jun 22 14:23:09] NOTICE[7420][C-0000005d] chan_sip.c: Failed to authenticate device <sip:%40@IP_REMOVED>;tag=93209c36
[Jun 22 14:23:12] NOTICE[7420][C-0000005e] chan_sip.c: Failed to authenticate device <sip:%40@IP_REMOVED>;tag=cf5b9246
[Jun 22 14:23:13] NOTICE[7420][C-0000005f] chan_sip.c: Failed to authenticate device <sip:%40@IP_REMOVED>;tag=ae0ff835
[Jun 22 14:23:27] NOTICE[7420] chan_sip.c: Registration from '<sip:%40@IP_REMOVED>' failed for '176.58.69.112:14398' - Wrong password
[Jun 22 14:24:08] NOTICE[7420] chan_sip.c: Registration from '<sip:%40@IP_REMOVED>' failed for '176.58.69.112:14398' - Wrong password
[Jun 22 14:24:21] NOTICE[7420][C-00000060] chan_sip.c: Failed to authenticate device 201<sip:201@IP_REMOVED>;tag=ba38c3c8
[Jun 22 14:25:28] NOTICE[7420] chan_sip.c: Registration from '<sip:%40@IP_REMOVED>' failed for '176.58.69.112:14398' - Wrong password
Given what I read from this, I would have expected the IP 176.58.69.112 to have been banned.
Why would the case of IP '' occur, and what steps would remedy this?
**** Update ****
The following messages were observed today in /var/log/secast:
2014-06-27T09:43:23, 00001403, D, Asterisk, IP '5.11.41.130' added to watch list
2014-06-27T09:43:23, 00000510, I, Asterisk, Detected potential intrustion attempt by username '1000' at IP '5.11.41.130' using protocol 'SIP' through security log '/var/log/asterisk/messages'
2014-06-27T09:43:43, 00001402, D, Asterisk, IP '5.11.41.130' on IP watch list with 2 potential intrusion attempts
2014-06-27T09:43:43, 00000510, I, Asterisk, Detected potential intrustion attempt by username '1000' at IP '5.11.41.130' using protocol 'SIP' through security log '/var/log/asterisk/messages'
2014-06-27T09:53:52, 00001405, D, Asterisk, IP '5.11.41.130' removed from IP watch list due to expiration
These resulted from the following lines in /var/log/asterisk/messages:
[Jun 27 09:43:23] NOTICE[1309] chan_sip.c: Registration from '<sip:1000@69.165.131.4>' failed for '5.11.41.130:12736' - Wrong password
[Jun 27 09:43:43] NOTICE[1309] chan_sip.c: Registration from '<sip:1000@69.165.131.4>' failed for '5.11.41.130:12736' - Wrong password
While there was an insufficient number of attempts to cause a ban to occur, it does appear that the IP address 5.11.41.130 was picked up as expected. Had there been more attempts, I'd guess that the ban attempt would have been successful this time.
Note that this time the username was simply '1000'; whereas, before the username was: '%40102' and '%40'
Is it possible that the % character was tripping up the secast parsing of the Asterisk messages line, causing the extraction of the IP address to fail?
I'll continue to monitor the logs for an actual ban event and report back.