Snort not restart on interface

bmeeks

Initiated by cron? You have periodic restarts enabled? So if one of these periodic restarts happens to coincide with a loss of sync by your modem and subsequent reset of the pppoe0 connection, then I can see how libpcap and Snort might get confused. For example, during the instant when the cron task is recycling PPPoE, Snort trys to connect to the interface and because the modem just lost sync and FreeBSD is trying to re-establish that interface, it is not available. Thus Snort and libpcap can't find it.

Is the cron task something you set up? If so, I would try disabling it for a bit.

If your PPPoE connection is so unstable that you need to resort to cron task restarts on some basis, I would go fuss at my ISP and have them fix the underlying issue with your connection.

fireodo

@bmeeks said in Snort not restart on interface:

Initiated by cron? You have periodic restarts enabled? So if one of these periodic restarts happens to coincide with a loss of sync by your modem and subsequent reset of the pppoe0 connection, then I can see how libpcap and Snort might get confused. For example, during the instant when the cron task is recycling PPPoE, Snort trys to connect to the interface and because the modem just lost sync and FreeBSD is trying to re-establish that interface, it is not available. Thus Snort and libpcap can't find it.

Is the cron task something you set up? If so, I would try disabling it for a bit.

Yes this is made by me and this works without problems - unfortunally the clog /var/log/system.log | grep snort doesnt cover the date where the unsync happend - thats why I asked you to send the HOLE syslog but not in public.

bmeeks

@fireodo said in Snort not restart on interface:

@bmeeks said in Snort not restart on interface:

Initiated by cron? You have periodic restarts enabled? So if one of these periodic restarts happens to coincide with a loss of sync by your modem and subsequent reset of the pppoe0 connection, then I can see how libpcap and Snort might get confused. For example, during the instant when the cron task is recycling PPPoE, Snort trys to connect to the interface and because the modem just lost sync and FreeBSD is trying to re-establish that interface, it is not available. Thus Snort and libpcap can't find it.

Is the cron task something you set up? If so, I would try disabling it for a bit.

Yes this is made by me and this works without problems - unfortunally the clog /var/log/system.log | grep snort doesnt cover the date where the unsync happend - thats why I asked you to send the HOLE syslog but not in public.

See my earlier reply. Your cron job can really confuse Snort if a periodic restart happens to occur at the same time an actual modem "loss of sync" event is being processed by pfSense. That can result in the cron task restarting Snort before the actual pppoe0 interface has been re-established by FreeBSD.

While loss of sync and connection issues are irritating, I think your cron task solution is a band-aid that might in some sense be making things potentially worse. If your connection is unstable, I would approach your Internet provider first instead of creating workarounds on the firewall.

fireodo

@bmeeks said in Snort not restart on interface:

@fireodo said in Snort not restart on interface:

@bmeeks said in Snort not restart on interface:

Initiated by cron? You have periodic restarts enabled? So if one of these periodic restarts happens to coincide with a loss of sync by your modem and subsequent reset of the pppoe0 connection, then I can see how libpcap and Snort might get confused. For example, during the instant when the cron task is recycling PPPoE, Snort trys to connect to the interface and because the modem just lost sync and FreeBSD is trying to re-establish that interface, it is not available. Thus Snort and libpcap can't find it.

Is the cron task something you set up? If so, I would try disabling it for a bit.

Yes this is made by me and this works without problems - unfortunally the clog /var/log/system.log | grep snort doesnt cover the date where the unsync happend - thats why I asked you to send the HOLE syslog but not in public.

See my earlier reply. Your cron job can really confuse Snort if a periodic restart happens to occur at the same time an actual modem "loss of sync" event is being processed by pfSense. That can result in the cron task restarting Snort before the actual pppoe0 interface has been re-established by FreeBSD.

While loss of sync and connection issues are irritating, I think your cron task solution is a band-aid that might in some sense be making things potentially worse. If your connection is unstable, I would approach your Internet provider first instead of creating workarounds on the firewall.

No No - the connection is not instable (as I write it was stable about 165 days) This voluntary reconnection daily is for other reasons.

Maybe this helps better: (this is when the resync of the modem occurs)

Mar 29 05:19:49 aragorn ppp: [wan_link0] LCP: no reply to 1 echo request(s)
Mar 29 05:19:55 aragorn php: lcdproc: Connection to LCDd process lost  ()
Mar 29 05:19:55 aragorn php: lcdproc: Start client procedure. Error counter: (0)
Mar 29 05:19:56 aragorn LCDd: Connect from host 127.0.0.1:56929 on socket 6
Mar 29 05:19:56 aragorn LCDd: sock_send: socket write error
Mar 29 05:19:58 aragorn LCDd: sock_send: socket write error
Mar 29 05:19:59 aragorn ppp: [wan_link0] LCP: no reply to 2 echo request(s)
Mar 29 05:20:00 aragorn LCDd: sock_send: socket write error
Mar 29 05:20:02 aragorn LCDd: sock_send: socket write error
Mar 29 05:20:04 aragorn LCDd: sock_send: socket write error
Mar 29 05:20:06 aragorn LCDd: sock_send: socket write error
Mar 29 05:20:08 aragorn LCDd: sock_send: socket write error
Mar 29 05:20:09 aragorn ppp: [wan_link0] LCP: no reply to 3 echo request(s)
Mar 29 05:20:10 aragorn LCDd: sock_send: socket write error
Mar 29 05:20:12 aragorn LCDd: sock_send: socket write error
Mar 29 05:20:14 aragorn LCDd: sock_send: socket write error
Mar 29 05:20:16 aragorn LCDd: sock_send: socket write error
Mar 29 05:20:18 aragorn LCDd: sock_send: socket write error
Mar 29 05:20:19 aragorn ppp: [wan_link0] LCP: no reply to 4 echo request(s)
Mar 29 05:20:20 aragorn LCDd: sock_send: socket write error
Mar 29 05:20:22 aragorn LCDd: sock_send: socket write error
Mar 29 05:20:24 aragorn LCDd: sock_send: socket write error
Mar 29 05:20:26 aragorn LCDd: sock_send: socket write error
Mar 29 05:20:28 aragorn LCDd: sock_send: socket write error
Mar 29 05:20:29 aragorn ppp: [wan_link0] LCP: no reply to 5 echo request(s)
Mar 29 05:20:29 aragorn ppp: [wan_link0] LCP: peer not responding to echo requests
Mar 29 05:20:29 aragorn ppp: [wan_link0] LCP: state change Opened --> Stopping
Mar 29 05:20:29 aragorn ppp: [wan_link0] Link: Leave bundle "wan"
Mar 29 05:20:29 aragorn ppp: [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps
Mar 29 05:20:29 aragorn ppp: [wan] IPCP: Close event
Mar 29 05:20:29 aragorn ppp: [wan] IPCP: state change Opened --> Closing
Mar 29 05:20:29 aragorn ppp: [wan] IPCP: SendTerminateReq #4
Mar 29 05:20:29 aragorn ppp: [wan] IPCP: LayerDown
Mar 29 05:20:29 aragorn php-cgi: rc.kill_states: rc.kill_states: Removing states for IP 1xxxxxxxxxxxxxxxxxxx/32
Mar 29 05:20:29 aragorn php-cgi: rc.kill_states: rc.kill_states: Removing states for interface pppoe0
Mar 29 05:20:29 aragorn check_reload_status: Rewriting resolv.conf
Mar 29 05:20:30 aragorn LCDd: Client on socket 6 disconnected
Mar 29 05:20:30 aragorn LCDd: sock_send: socket write error
Mar 29 05:20:31 aragorn LCDd: Server shutting down on SIGTERM
Mar 29 05:20:31 aragorn LCDd: sock_send: socket write error
Mar 29 05:20:32 aragorn ppp: [wan] IPV6CP: Close event
Mar 29 05:20:32 aragorn ppp: [wan] IPV6CP: state change Opened --> Closing
Mar 29 05:20:32 aragorn ppp: [wan] IPV6CP: SendTerminateReq #2
Mar 29 05:20:32 aragorn ppp: [wan] IPV6CP: LayerDown
Mar 29 05:20:32 aragorn php-cgi: rc.kill_states: rc.kill_states: Removing states for IP fe80:xxxxxxxxc%pppoe0/32
Mar 29 05:20:32 aragorn php-cgi: rc.kill_states: rc.kill_states: Removing states for interface pppoe0
Mar 29 05:20:33 aragorn check_reload_status: Rewriting resolv.conf
Mar 29 05:20:33 aragorn ppp: [wan] IFACE: Down event
Mar 29 05:20:33 aragorn ppp: [wan] IFACE: Rename interface pppoe0 to pppoe0
Mar 29 05:20:33 aragorn ppp: [wan] IPCP: Down event
Mar 29 05:20:33 aragorn ppp: [wan] IPCP: LayerFinish
Mar 29 05:20:33 aragorn ppp: [wan] IPCP: state change Closing --> Initial
Mar 29 05:20:33 aragorn ppp: [wan] IPV6CP: Down event
Mar 29 05:20:33 aragorn ppp: [wan] IPV6CP: LayerFinish
Mar 29 05:20:33 aragorn ppp: [wan] Bundle: No NCPs left. Closing links...
Mar 29 05:20:33 aragorn ppp: [wan] IPV6CP: state change Closing --> Initial
Mar 29 05:20:33 aragorn ppp: [wan_link0] LCP: SendTerminateReq #2
Mar 29 05:20:33 aragorn ppp: [wan_link0] LCP: LayerDown
Mar 29 05:20:40 aragorn ppp: [wan_link0] LCP: SendTerminateReq #3
Mar 29 05:20:42 aragorn ppp: [wan_link0] LCP: state change Stopping --> Stopped
Mar 29 05:20:42 aragorn ppp: [wan_link0] LCP: LayerFinish
Mar 29 05:20:42 aragorn ppp: [wan_link0] PPPoE: connection closed
Mar 29 05:20:42 aragorn ppp: [wan_link0] Link: DOWN event
Mar 29 05:20:42 aragorn ppp: [wan_link0] LCP: Down event
Mar 29 05:20:42 aragorn ppp: [wan_link0] LCP: state change Stopped --> Starting
Mar 29 05:20:42 aragorn ppp: [wan_link0] LCP: LayerStart
Mar 29 05:20:42 aragorn ppp: [wan_link0] Link: reconnection attempt 1 in 4 seconds
Mar 29 05:20:46 aragorn ppp: [wan_link0] Link: reconnection attempt 1
Mar 29 05:20:46 aragorn ppp: [wan_link0] PPPoE: Connecting to 'provider'
Mar 29 05:20:55 aragorn ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Mar 29 05:20:55 aragorn ppp: [wan_link0] Link: DOWN event
Mar 29 05:20:55 aragorn ppp: [wan_link0] LCP: Down event
Mar 29 05:20:55 aragorn ppp: [wan_link0] Link: reconnection attempt 2 in 1 seconds
Mar 29 05:20:56 aragorn ppp: [wan_link0] Link: reconnection attempt 2
Mar 29 05:20:56 aragorn ppp: [wan_link0] PPPoE: Connecting to 'provider'
Mar 29 05:20:58 aragorn ppp: PPPoE: rec'd ACNAME "XXXXXX"
Mar 29 05:20:58 aragorn ppp: [wan_link0] PPPoE: connection successful
Mar 29 05:20:58 aragorn ppp: [wan_link0] Link: UP event
Mar 29 05:20:58 aragorn ppp: [wan_link0] LCP: Up event
Mar 29 05:20:58 aragorn ppp: [wan_link0] LCP: state change Starting --> Req-Sent
Mar 29 05:20:58 aragorn ppp: [wan_link0] LCP: SendConfigReq #4
Mar 29 05:20:58 aragorn ppp: [wan_link0]   PROTOCOMP
Mar 29 05:20:58 aragorn ppp: [wan_link0]   MRU 1492
Mar 29 05:20:58 aragorn ppp: [wan_link0]   MAGICNUM 0x8202dc20
Mar 29 05:20:58 aragorn ppp: [wan_link0] LCP: rec'd Configure Request #152 (Req-Sent)
Mar 29 05:20:58 aragorn ppp: [wan_link0]   MRU 1492
Mar 29 05:20:58 aragorn ppp: [wan_link0]   AUTHPROTO PAP
Mar 29 05:20:58 aragorn ppp: [wan_link0]   MAGICNUM 0x476128d2
Mar 29 05:20:58 aragorn ppp: [wan_link0] LCP: SendConfigAck #152
Mar 29 05:20:58 aragorn ppp: [wan_link0]   MRU 1492
Mar 29 05:20:58 aragorn ppp: [wan_link0]   AUTHPROTO PAP
Mar 29 05:20:58 aragorn ppp: [wan_link0]   MAGICNUM 0x476128d2
Mar 29 05:20:58 aragorn ppp: [wan_link0] LCP: state change Req-Sent --> Ack-Sent
Mar 29 05:20:58 aragorn ppp: [wan_link0] LCP: rec'd Configure Ack #4 (Ack-Sent)
Mar 29 05:20:58 aragorn ppp: [wan_link0]   PROTOCOMP
Mar 29 05:20:58 aragorn ppp: [wan_link0]   MRU 1492
Mar 29 05:20:58 aragorn ppp: [wan_link0]   MAGICNUM 0x8202dc20
Mar 29 05:20:58 aragorn ppp: [wan_link0] LCP: state change Ack-Sent --> Opened
Mar 29 05:20:58 aragorn ppp: [wan_link0] LCP: auth: peer wants PAP, I want nothing
Mar 29 05:20:58 aragorn ppp: [wan_link0] PAP: using authname "xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx"
Mar 29 05:20:58 aragorn ppp: [wan_link0] PAP: sending REQUEST #1 len: 54
Mar 29 05:20:58 aragorn ppp: [wan_link0] LCP: LayerUp
Mar 29 05:20:58 aragorn ppp: [wan_link0] PAP: rec'd ACK #1 len: 25
Mar 29 05:20:58 aragorn ppp: [wan_link0]   MESG: SRU=11992#SRD=59961#
Mar 29 05:20:58 aragorn ppp: [wan_link0] LCP: authorization successful
Mar 29 05:20:58 aragorn ppp: [wan_link0] Link: Matched action 'bundle "wan" ""'
Mar 29 05:20:58 aragorn ppp: [wan_link0] Link: Join bundle "wan"
Mar 29 05:20:58 aragorn ppp: [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps
Mar 29 05:20:58 aragorn ppp: [wan] IPCP: Open event
Mar 29 05:20:58 aragorn ppp: [wan] IPCP: state change Initial --> Starting
Mar 29 05:20:58 aragorn ppp: [wan] IPCP: LayerStart
Mar 29 05:20:58 aragorn ppp: [wan] IPV6CP: Open event
Mar 29 05:20:58 aragorn ppp: [wan] IPV6CP: state change Initial --> Starting
Mar 29 05:20:58 aragorn ppp: [wan] IPV6CP: LayerStart
Mar 29 05:20:58 aragorn ppp: [wan] IPCP: Up event
Mar 29 05:20:58 aragorn ppp: [wan] IPCP: state change Starting --> Req-Sent
Mar 29 05:20:58 aragorn ppp: [wan] IPCP: SendConfigReq #5
Mar 29 05:20:58 aragorn ppp: [wan]   IPADDR 0.0.0.0
Mar 29 05:20:58 aragorn ppp: [wan]   COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Mar 29 05:20:58 aragorn ppp: [wan] IPV6CP: Up event
Mar 29 05:20:58 aragorn ppp: [wan] IPV6CP: state change Starting --> Req-Sent
Mar 29 05:20:58 aragorn ppp: [wan] IPV6CP: SendConfigReq #3
Mar 29 05:20:58 aragorn ppp: [wan] IPCP: rec'd Configure Request #94 (Req-Sent)
Mar 29 05:20:58 aragorn ppp: [wan]   IPADDR provider-gateway-IP
Mar 29 05:20:58 aragorn ppp: [wan]     provider-gateway-IP is OK
Mar 29 05:20:58 aragorn ppp: [wan] IPCP: SendConfigAck #94
Mar 29 05:20:58 aragorn ppp: [wan]   IPADDR provider-gateway-IP
Mar 29 05:20:58 aragorn ppp: [wan] IPCP: state change Req-Sent --> Ack-Sent
Mar 29 05:20:58 aragorn ppp: [wan] IPCP: rec'd Configure Reject #5 (Ack-Sent)
Mar 29 05:20:58 aragorn ppp: [wan]   COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Mar 29 05:20:58 aragorn ppp: [wan] IPCP: SendConfigReq #6
Mar 29 05:20:58 aragorn ppp: [wan]   IPADDR 0.0.0.0
Mar 29 05:20:58 aragorn ppp: [wan] IPV6CP: rec'd Configure Request #39 (Req-Sent)
Mar 29 05:20:58 aragorn ppp: [wan] IPV6CP: SendConfigAck #39
Mar 29 05:20:58 aragorn ppp: [wan] IPV6CP: state change Req-Sent --> Ack-Sent
Mar 29 05:20:58 aragorn ppp: [wan] IPCP: rec'd Configure Nak #6 (Ack-Sent)
Mar 29 05:20:58 aragorn ppp: [wan]   IPADDR 1xxxxxxxxxxxxxxxxxxx
Mar 29 05:20:58 aragorn ppp: [wan]     1xxxxxxxxxxxxxxxxxxx is OK
Mar 29 05:20:58 aragorn ppp: [wan] IPCP: SendConfigReq #7
Mar 29 05:20:58 aragorn ppp: [wan]   IPADDR 1xxxxxxxxxxxxxxxxxxx
Mar 29 05:20:58 aragorn ppp: [wan] IPCP: rec'd Configure Ack #7 (Ack-Sent)
Mar 29 05:20:58 aragorn ppp: [wan]   IPADDR 1xxxxxxxxxxxxxxxxxxx
Mar 29 05:20:58 aragorn ppp: [wan] IPCP: state change Ack-Sent --> Opened
Mar 29 05:20:58 aragorn ppp: [wan] IPCP: LayerUp
Mar 29 05:20:58 aragorn ppp: [wan]   1xxxxxxxxxxxxxxxxxxx -> provider-gateway-IP
Mar 29 05:20:58 aragorn check_reload_status: rc.newwanip starting pppoe0
Mar 29 05:20:59 aragorn ppp: [wan] IFACE: Up event
Mar 29 05:20:59 aragorn ppp: [wan] IFACE: Rename interface ng0 to pppoe0
Mar 29 05:20:59 aragorn ppp: [wan] IPV6CP: rec'd Configure Ack #3 (Ack-Sent)
Mar 29 05:20:59 aragorn ppp: [wan] IPV6CP: state change Ack-Sent --> Opened
Mar 29 05:20:59 aragorn ppp: [wan] IPV6CP: LayerUp
Mar 29 05:20:59 aragorn ppp: [wan]   0xxxxxxxxxxxxxxxxxxx -> 1xxxxxxxxxxxxxxxxxxx
Mar 29 05:20:59 aragorn check_reload_status: rc.newwanipv6 starting pppoe0
Mar 29 05:20:59 aragorn ppp: [wan_link0] rec'd unexpected protocol IPv6
Mar 29 05:20:59 aragorn php-fpm[64679]: /rc.newwanip: rc.newwanip: Info: starting on pppoe0.
Mar 29 05:20:59 aragorn php-fpm[64679]: /rc.newwanip: rc.newwanip: on (IP address: 1xxxxxxxxxxxxxxxxxxx) (interface: DSL[wan]) (real interface: pppoe0).
Mar 29 05:21:00 aragorn xinetd[24731]: Starting reconfiguration
Mar 29 05:21:00 aragorn xinetd[24731]: Swapping defaults
Mar 29 05:21:00 aragorn xinetd[24731]: readjusting service 19000-tcp
Mar 29 05:21:00 aragorn xinetd[24731]: readjusting service 19001-tcp
Mar 29 05:21:00 aragorn xinetd[24731]: readjusting service 19002-tcp
Mar 29 05:21:00 aragorn xinetd[24731]: Reconfigured: new=0 old=3 dropped=0 (services)
Mar 29 05:21:00 aragorn php-fpm[34513]: /rc.newwanipv6: rc.newwanipv6: Info: starting on pppoe0.
Mar 29 05:21:00 aragorn php-fpm[34513]: /rc.newwanipv6: rc.newwanipv6: No IPv6 address found for interface DSL [wan].
Mar 29 05:21:15 aragorn php-fpm[64679]: /rc.newwanip: Removing static route for monitor 9.9.9.9 and adding a new route through provider-gateway-IP
Mar 29 05:21:15 aragorn php-fpm[64679]: /rc.newwanip: Default gateway setting provider IP4-Gateway as default.
Mar 29 05:21:15 aragorn php-fpm[64679]: /rc.newwanip: IP Address has changed, killing all states (ip_change_kill_states is set).
Mar 29 05:21:27 aragorn php-fpm[64679]: /rc.newwanip: phpDynDNS: updating cache file /conf/dyndns_wan------------'0.cache: 1xxxxxxxxxxxxxxxxxxx
Mar 29 05:21:27 aragorn php-fpm[64679]: /rc.newwanip: phpDynDNS (dyndns): (Success) IP Address Changed Successfully! (1xxxxxxxxxxxxxxxxxxx)
Mar 29 05:21:28 aragorn php-cgi: notify_monitor.php: Message sent to xx@xx.xx OK
Mar 29 05:21:30 aragorn php-fpm[64679]: /rc.newwanip: phpDynDNS: updating cache file /conf/dyndns_wan------------'1.cache: 1xxxxxxxxxxxxxxxxxxx
Mar 29 05:21:30 aragorn php-fpm[64679]: /rc.newwanip: phpDynDNS (dyndns): (Success) IP Address Changed Successfully!
Mar 29 05:21:31 aragorn php-fpm[64679]: /rc.newwanip: Resyncing OpenVPN instances for interface DSL.
Mar 29 05:21:31 aragorn php-fpm[64679]: /rc.newwanip: Creating rrd update script
Mar 29 05:21:34 aragorn php-fpm[64679]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 0xxxxxxxxxxxxxxxxxxx ->  1xxxxxxxxxxxxxxxxxxx - Restarting packages.
Mar 29 05:21:34 aragorn check_reload_status: Starting packages
Mar 29 05:21:35 aragorn php-fpm[34513]: /rc.start_packages: Restarting/Starting all packages.
Mar 29 05:21:35 aragorn php-fpm[34513]: lcdproc: Sync: Begin package sync
Mar 29 05:21:35 aragorn php-fpm[34513]: lcdproc: Sync: End package sync
Mar 29 05:21:35 aragorn LCDd: LCDd version 0.5.9 starting
Mar 29 05:21:35 aragorn LCDd: Using Configuration File: /usr/local/etc/LCDd.conf
Mar 29 05:21:35 aragorn LCDd: Listening for queries on 127.0.0.1:13666
Mar 29 05:21:38 aragorn php: lcdproc: Start client procedure. Error counter: (0)
Mar 29 05:21:38 aragorn php-cgi: notify_monitor.php: Message sent to xx@xx.xx OK
Mar 29 05:21:39 aragorn LCDd: Connect from host 127.0.0.1:15632 on socket 6
Mar 29 05:21:40 aragorn check_reload_status: Syncing firewall
Mar 29 05:21:40 aragorn check_reload_status: Reloading filter
Mar 29 05:21:40 aragorn php-fpm[34513]: [pfBlockerNG] Restarting firewall filter daemon
Mar 29 05:21:42 aragorn php: [pfBlockerNG] DNSBL parser daemon started
Mar 29 05:21:42 aragorn php_pfb: [pfBlockerNG] filterlog daemon started
Mar 29 05:21:42 aragorn xinetd[24731]: Starting reconfiguration
Mar 29 05:21:42 aragorn xinetd[24731]: Swapping defaults
Mar 29 05:21:42 aragorn xinetd[24731]: readjusting service 19000-tcp
Mar 29 05:21:42 aragorn xinetd[24731]: readjusting service 19001-tcp
Mar 29 05:21:42 aragorn xinetd[24731]: readjusting service 19002-tcp
Mar 29 05:21:42 aragorn xinetd[24731]: Reconfigured: new=0 old=3 dropped=0 (services)
Mar 29 05:30:00 aragorn php: [pfBlockerNG] Starting cron process.
Mar 29 05:30:06 aragorn php: [pfBlockerNG] No changes to Firewall rules, skipping Filter Reload

bmeeks

Those log entries indicate either an issue with your provider's subsystem (not the physical layer perhaps, but the logical one instead). Or it could be problems in the PPPoE daemon within pfSense. That area is not within my expertise.

What is puzzling is why, a the end of that log when pfSense logs a "...restarting packages..." command, that I see it restart pfBlockerNG but not Snort. Snort is like every typical package and puts a shell script entry in the config.xml file so pfSense can find the shell script and execute Snort service stops and starts.

fireodo

@bmeeks said in Snort not restart on interface:

Those log entries indicate either an issue with your provider's subsystem (not the physical layer perhaps, but the logical one instead). Or it could be problems in the PPPoE daemon within pfSense. That area is not within my expertise.

What is puzzling is why, a the end of that log when pfSense logs a "...restarting packages..." command, that I see it restart pfBlockerNG but not Snort. Snort is like every typical package and puts a shell script entry in the config.xml file so pfSense can find the shell script and execute Snort service stops and starts.
Thats correct: ```
<rcfile>snort.sh</rcfile>
<executable>snort</executable>

Thats why I tried to uninstall and reinstall snort ...

bmeeks

@fireodo said in Snort not restart on interface:

Thats why I tried to uninstall and reinstall snort ...

I'm looking into it. Is this behavior something you just noticed after upgrading to 2.4.5?

fireodo

@bmeeks said in Snort not restart on interface:

@fireodo said in Snort not restart on interface:

Thats why I tried to uninstall and reinstall snort ...

I'm looking into it. Is this behavior something you just noticed after upgrading to 2.4.5?

I noticed it after upgrading to 2.4.5 but only because of the coincidence that my provider has initiated a Modem resync in the weekend night (this is usually when they have something to maintain) right after the update but its very possible that this behavior is also in 2.4.4-RELEASE-p3 (all the time i was running this version no resync occured :-)

bmeeks

Okay. Give me some time to investigate in a virtual machine. I also have to look into a Suricata problem on aarch64 hardware for the pfSense team, so it may be a day or two. The only thing I can imagine at this point is maybe something is different in the rc.start_packages script and I need to make an adjustment to how the Snort package interracts with it. Just a guess at this point, though.

However, even should I find an issue there, I still think you having the cron task will eventually be problematic should its execution happen to coincide with a time when pfSense is responding to one of those loss-of-lcp signal issues.

fireodo

@bmeeks said in Snort not restart on interface:

Okay. Give me some time to investigate in a virtual machine. I also have to look into a Suricata problem on aarch64 hardware for the pfSense team, so it may be a day or two. The only thing I can imagine at this point is maybe something is different in the rc.start_packages script and I need to make an adjustment to how the Snort package interracts with it. Just a guess at this point, though.

However, even should I find an issue there, I still think you having the cron task will eventually be problematic should its execution happen to coincide with a time when pfSense is responding to one of those loss-of-lcp signal issues.

The cron task is normally in the middle of the night (at 2:10) the probability to do the reconnection on a modem resync is like gaining in Lotto :-)
I hope not to put you on a wrong way. Thank you VERY MUCH for your time and pacience!

Regards,
fireodo

bmeeks

I took some time to have a quick look in a 2.4.5 virtual machine before starting on the Suricata issue. I can see nothing wrong with the interraction of Snort and the rc.start_packages script. Everything starts and stops fine in the virtual machine. I don't know what exactly it would be, but I now suspect something unique to your setup.

Examine your config.xml file for the firewall. It should have a section for <installedpackages><service>, and the <service> section for Snort should look like this --

	<service>
		<name>snort</name>
		<rcfile>snort.sh</rcfile>
		<executable>snort</executable>
		<description><![CDATA[Snort IDS/IPS Daemon]]></description>
	</service>

This is the section that the rc.start_packges script scans to find the shell script to execute when starting packages. This same script and section gets called when you boot up the firewall as well. Does Snort start by itself on a firewall reboot, or do you have to intervene manually?

One thing I suggest you add to your cron task is a command to shut down Snort and then later restart it again from inside the cron task. Use these commands:

/usr/local/etc/rc.d/snort.sh stop
sleep 10
/usr/local/etc/rc.d/snort.sh start

The sleep() command is only required if the stop and start are immediately adjacent to each other. I suggest stopping Snort BEFORE you cycle the PPPoE interface, and then starting Snort again only AFTER the PPPoE interface is back up.

fireodo

@bmeeks said in Snort not restart on interface:

I took some time to have a quick look in a 2.4.5 virtual machine before starting on the Suricata issue. I can see nothing wrong with the interraction of Snort and the rc.start_packages script. Everything starts and stops fine in the virtual machine. I don't know what exactly it would be, but I now suspect something unique to your setup.

Examine your config.xml file for the firewall. It should have a section for <installedpackages><service>, and the <service> section for Snort should look like this --
  <service>
  	<name>snort</name>
  	<rcfile>snort.sh</rcfile>
  	<executable>snort</executable>
  	<description><![CDATA[Snort IDS/IPS Daemon]]></description>
  </service>

Is exactly so present in my config.

This is the section that the rc.start_packges script scans to find the shell script to execute when starting packages. This same script and section gets called when you boot up the firewall as well. Does Snort start by itself on a firewall reboot, or do you have to intervene manually?

Snort starts on reboot by itself no need to intervene manually.

One thing I suggest you add to your cron task is a command to shut down Snort and then later restart it again from inside the cron task. Use these commands:
/usr/local/etc/rc.d/snort.sh stop
sleep 10
/usr/local/etc/rc.d/snort.sh start
The sleep() command is only required if the stop and start are immediately adjacent to each other. I suggest stopping Snort BEFORE you cycle the PPPoE interface, and then starting Snort again only AFTER the PPPoE interface is back up.

On normal cycling of pppoe connection snort starts correctly and works correctly - only in case of modem loose connection it makes problems.

I added your command to stop/start snort at the end of the /usr/local/sbin/ppp-linkup script and now snort stays functional even if the modem resyncs! I know thats only a workaraound but I can live with it! Good Night!

bmeeks

@fireodo said in Snort not restart on interface:

@bmeeks said in Snort not restart on interface:
I took some time to have a quick look in a 2.4.5 virtual machine before starting on the Suricata issue. I can see nothing wrong with the interraction of Snort and the rc.start_packages script. Everything starts and stops fine in the virtual machine. I don't know what exactly it would be, but I now suspect something unique to your setup.

Examine your config.xml file for the firewall. It should have a section for <installedpackages><service>, and the <service> section for Snort should look like this --
  <service>
  	<name>snort</name>
  	<rcfile>snort.sh</rcfile>
  	<executable>snort</executable>
  	<description><![CDATA[Snort IDS/IPS Daemon]]></description>
  </service>
Is exactly so present in my config.

This is the section that the rc.start_packges script scans to find the shell script to execute when starting packages. This same script and section gets called when you boot up the firewall as well. Does Snort start by itself on a firewall reboot, or do you have to intervene manually?

Snort starts on reboot by itself no need to intervene manually.
One thing I suggest you add to your cron task is a command to shut down Snort and then later restart it again from inside the cron task. Use these commands:
/usr/local/etc/rc.d/snort.sh stop
sleep 10
/usr/local/etc/rc.d/snort.sh start
The sleep() command is only required if the stop and start are immediately adjacent to each other. I suggest stopping Snort BEFORE you cycle the PPPoE interface, and then starting Snort again only AFTER the PPPoE interface is back up.
On normal cycling of pppoe connection snort starts correctly and works correctly - only in case of modem loose connection it makes problems.

Would it be a good idea to add this command you suggested to the /usr/local/sbin/ppp-linkup script?

I don't think it would hurt anything, but of course it would get wiped out with the next upgrade and you would have to remember to edit the script again.

I'm really not a PPPoE expert. I had DSL way, way back and dealt with PPPoE just a bit back then. But luckily with my carrier at the time, and with the DSL modem I had, I was able to switch over to PPPoA (PPP over ATM). I did that to take advantage of the full 1500-byte MTU instead of having to limit my MTU to 1492.

So you say your modem is in bridge mode, but I don't believe it actually is if you have a pppoe0 connection in pfsense. Or at least that's not how my DSL modem worked. I put the password and login name in the modem and it handled all the PPP stuff. What I got on the LAN side of the modem was a DHCP address (the public IP assigned by my ISP). Does your modem not support a mode of operation like that? It's been a long time, so maybe that was how the PPPoA worked for me and PPPoE would have been different.

Edit: the more I've tried to remember, perhaps I am remembering wrong for PPPoE. Maybe it did put a PPP interface on my pfSense and only the PPPoA mode was DHCP on the firewall side. That was 17 years ago and I can't recall the details now.

fireodo

@bmeeks said in Snort not restart on interface:

@fireodo said in Snort not restart on interface:
@bmeeks said in Snort not restart on interface:
I took some time to have a quick look in a 2.4.5 virtual machine before starting on the Suricata issue. I can see nothing wrong with the interraction of Snort and the rc.start_packages script. Everything starts and stops fine in the virtual machine. I don't know what exactly it would be, but I now suspect something unique to your setup.

Examine your config.xml file for the firewall. It should have a section for <installedpackages><service>, and the <service> section for Snort should look like this --
  <service>
  	<name>snort</name>
  	<rcfile>snort.sh</rcfile>
  	<executable>snort</executable>
  	<description><![CDATA[Snort IDS/IPS Daemon]]></description>
  </service>
Is exactly so present in my config.

This is the section that the rc.start_packges script scans to find the shell script to execute when starting packages. This same script and section gets called when you boot up the firewall as well. Does Snort start by itself on a firewall reboot, or do you have to intervene manually?

Snort starts on reboot by itself no need to intervene manually.
One thing I suggest you add to your cron task is a command to shut down Snort and then later restart it again from inside the cron task. Use these commands:
/usr/local/etc/rc.d/snort.sh stop
sleep 10
/usr/local/etc/rc.d/snort.sh start
The sleep() command is only required if the stop and start are immediately adjacent to each other. I suggest stopping Snort BEFORE you cycle the PPPoE interface, and then starting Snort again only AFTER the PPPoE interface is back up.
On normal cycling of pppoe connection snort starts correctly and works correctly - only in case of modem loose connection it makes problems.

Would it be a good idea to add this command you suggested to the /usr/local/sbin/ppp-linkup script?
I don't think it would hurt anything, but of course it would get wiped out with the next upgrade and you would have to remember to edit the script again.

That I have to do, thats no problem ... :-)

kiokoman

the more i think about it the more i find it strange

i put up a virtual machine and tested it myself

Mar 31 20:38:27	php-fpm	95633	/rc.start_packages: Restarting/Starting all packages.
Mar 31 20:38:26	check_reload_status	381	Starting packages
Mar 31 20:38:26	php-fpm	343	/rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 192.168.78.2 -> 192.168.78.2 - Restarting packages.
Mar 31 20:38:24	php-fpm	343	/rc.newwanip: Creating rrd update script
Mar 31 20:38:24	php-fpm	343	/rc.newwanip: Resyncing OpenVPN instances for interface OPT1.
Mar 31 20:38:21	php-fpm	343	/rc.newwanip: rc.newwanip: on (IP address: 192.168.78.2) (interface: OPT1[opt1]) (real interface: pppoe0).
Mar 31 20:38:21	php-fpm	343	/rc.newwanip: rc.newwanip: Info: starting on pppoe0.
Mar 31 20:38:20	ppp	12008	[opt1] IFACE: Rename interface ng0 to pppoe0
Mar 31 20:38:20	ppp	12008	[opt1] IFACE: Up event
Mar 31 20:38:20	check_reload_status	381	rc.newwanip starting pppoe0
Mar 31 20:38:19	check_reload_status	381	Rewriting resolv.conf
Mar 31 20:38:19	ppp	12008	[opt1] 192.168.78.2 -> 192.168.77.1
Mar 31 20:38:19	ppp	12008	[opt1] IPCP: LayerUp
Mar 31 20:38:19	ppp	12008	[opt1] IPCP: state change Ack-Sent --> Opened
Mar 31 20:38:19	ppp	12008	[opt1] PRIDNS 172.17.0.100
Mar 31 20:38:19	ppp	12008	[opt1] IPADDR 192.168.78.2
Mar 31 20:38:19	ppp	12008	[opt1] IPCP: rec'd Configure Ack #8 (Ack-Sent)
Mar 31 20:38:19	ppp	12008	[opt1] PRIDNS 172.17.0.100
Mar 31 20:38:19	ppp	12008	[opt1] IPADDR 192.168.78.2
Mar 31 20:38:19	ppp	12008	[opt1] IPCP: SendConfigReq #8
Mar 31 20:38:19	ppp	12008	[opt1] PRIDNS 172.17.0.100
Mar 31 20:38:19	ppp	12008	[opt1] 192.168.78.2 is OK
Mar 31 20:38:19	ppp	12008	[opt1] IPADDR 192.168.78.2
Mar 31 20:38:19	ppp	12008	[opt1] IPCP: rec'd Configure Nak #7 (Ack-Sent)
Mar 31 20:38:19	ppp	12008	[opt1] PRIDNS 0.0.0.0
Mar 31 20:38:19	ppp	12008	[opt1] IPADDR 0.0.0.0
Mar 31 20:38:19	ppp	12008	[opt1] IPCP: SendConfigReq #7
Mar 31 20:38:19	ppp	12008	[opt1] SECDNS 0.0.0.0
Mar 31 20:38:19	ppp	12008	[opt1] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Mar 31 20:38:19	ppp	12008	[opt1] IPCP: rec'd Configure Reject #6 (Ack-Sent)
Mar 31 20:38:19	ppp	12008	[opt1_link0] rec'd unexpected protocol CCP, rejecting
Mar 31 20:38:19	ppp	12008	[opt1] IPCP: state change Req-Sent --> Ack-Sent
Mar 31 20:38:19	ppp	12008	[opt1] IPADDR 192.168.77.1
Mar 31 20:38:19	ppp	12008	[opt1] IPCP: SendConfigAck #1
Mar 31 20:38:19	ppp	12008	[opt1] 192.168.77.1 is OK
Mar 31 20:38:19	ppp	12008	[opt1] IPADDR 192.168.77.1
Mar 31 20:38:19	ppp	12008	[opt1] IPCP: rec'd Configure Request #1 (Req-Sent)
Mar 31 20:38:19	ppp	12008	[opt1] SECDNS 0.0.0.0
Mar 31 20:38:19	ppp	12008	[opt1] PRIDNS 0.0.0.0
Mar 31 20:38:19	ppp	12008	[opt1] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Mar 31 20:38:19	ppp	12008	[opt1] IPADDR 0.0.0.0
Mar 31 20:38:19	ppp	12008	[opt1] IPCP: SendConfigReq #6
Mar 31 20:38:19	ppp	12008	[opt1] IPCP: state change Starting --> Req-Sent
Mar 31 20:38:19	ppp	12008	[opt1] IPCP: Up event
Mar 31 20:38:19	ppp	12008	[opt1] IPCP: LayerStart
Mar 31 20:38:19	ppp	12008	[opt1] IPCP: state change Initial --> Starting
Mar 31 20:38:19	ppp	12008	[opt1] IPCP: Open event
Mar 31 20:38:19	ppp	12008	[opt1] Bundle: Status update: up 1 link, total bandwidth 64000 bps
Mar 31 20:38:19	ppp	12008	[opt1_link0] Link: Join bundle "opt1"
Mar 31 20:38:19	ppp	12008	[opt1_link0] Link: Matched action 'bundle "opt1" ""'
Mar 31 20:38:19	ppp	12008	[opt1_link0] LCP: authorization successful
Mar 31 20:38:19	ppp	12008	[opt1_link0] MESG: Welcome
Mar 31 20:38:19	ppp	12008	[opt1_link0] PAP: rec'd ACK #1 len: 12
Mar 31 20:38:19	ppp	12008	[opt1_link0] LCP: LayerUp
Mar 31 20:38:19	ppp	12008	[opt1_link0] PAP: sending REQUEST #1 len: 14
Mar 31 20:38:19	ppp	12008	[opt1_link0] PAP: using authname "test"
Mar 31 20:38:19	ppp	12008	[opt1_link0] LCP: auth: peer wants PAP, I want nothing
Mar 31 20:38:19	ppp	12008	[opt1_link0] LCP: state change Ack-Sent --> Opened
Mar 31 20:38:19	ppp	12008	[opt1_link0] MAGICNUM 0xe92dbee8
Mar 31 20:38:19	ppp	12008	[opt1_link0] MRU 1492
Mar 31 20:38:19	ppp	12008	[opt1_link0] PROTOCOMP
Mar 31 20:38:19	ppp	12008	[opt1_link0] LCP: rec'd Configure Ack #3 (Ack-Sent)
Mar 31 20:38:19	ppp	12008	[opt1_link0] LCP: state change Req-Sent --> Ack-Sent
Mar 31 20:38:19	ppp	12008	[opt1_link0] AUTHPROTO PAP
Mar 31 20:38:19	ppp	12008	[opt1_link0] MAGICNUM 0xe7f15140
Mar 31 20:38:19	ppp	12008	[opt1_link0] MRU 1492
Mar 31 20:38:19	ppp	12008	[opt1_link0] PROTOCOMP
Mar 31 20:38:19	ppp	12008	[opt1_link0] LCP: SendConfigAck #1
Mar 31 20:38:19	ppp	12008	[opt1_link0] AUTHPROTO PAP
Mar 31 20:38:19	ppp	12008	[opt1_link0] MAGICNUM 0xe7f15140
Mar 31 20:38:19	ppp	12008	[opt1_link0] MRU 1492
Mar 31 20:38:19	ppp	12008	[opt1_link0] PROTOCOMP
Mar 31 20:38:19	ppp	12008	[opt1_link0] LCP: rec'd Configure Request #1 (Req-Sent)
Mar 31 20:38:19	ppp	12008	[opt1_link0] MAGICNUM 0xe92dbee8
Mar 31 20:38:19	ppp	12008	[opt1_link0] MRU 1492
Mar 31 20:38:19	ppp	12008	[opt1_link0] PROTOCOMP
Mar 31 20:38:19	ppp	12008	[opt1_link0] LCP: SendConfigReq #3
Mar 31 20:38:19	ppp	12008	[opt1_link0] LCP: state change Starting --> Req-Sent
Mar 31 20:38:19	ppp	12008	[opt1_link0] LCP: Up event
Mar 31 20:38:19	ppp	12008	[opt1_link0] Link: UP event
Mar 31 20:38:19	ppp	12008	[opt1_link0] PPPoE: connection successful
Mar 31 20:38:19	ppp	12008	PPPoE: rec'd ACNAME "pfSense.kiokoman.home"
Mar 31 20:38:17	ppp	12008	[opt1_link0] PPPoE: Connecting to ''
Mar 31 20:38:17	ppp	12008	[opt1_link0] Link: reconnection attempt 20
Mar 31 20:38:13	ppp	12008	[opt1_link0] Link: reconnection attempt 20 in 4 seconds
......
Mar 31 20:34:31	ppp	12008	[opt1] IPCP: LayerFinish
Mar 31 20:34:31	ppp	12008	[opt1] IPCP: Down event
Mar 31 20:34:31	ppp	12008	[opt1] IPCP: state change Stopping --> Closing
Mar 31 20:34:31	ppp	12008	[opt1] IPCP: Close event
Mar 31 20:34:31	ppp	12008	[opt1] Bundle: Status update: up 0 links, total bandwidth 9600 bps
Mar 31 20:34:31	ppp	12008	[opt1_link0] Link: Leave bundle "opt1"
Mar 31 20:34:31	ppp	12008	[opt1_link0] LCP: state change Opened --> Stopping
Mar 31 20:34:31	ppp	12008	[opt1_link0] LCP: rec'd Terminate Request #2 (Opened)
Mar 31 20:34:31	ppp	12008	[opt1] IFACE: Rename interface pppoe0 to pppoe0
Mar 31 20:34:31	ppp	12008	[opt1] IFACE: Down event
Mar 31 20:34:31	check_reload_status	381	Rewriting resolv.conf
Mar 31 20:34:30	ppp	12008	[opt1] IPCP: LayerDown
Mar 31 20:34:30	ppp	12008	[opt1] IPCP: SendTerminateAck #5
Mar 31 20:34:30	ppp	12008	[opt1] IPCP: state change Opened --> Stopping
Mar 31 20:34:30	ppp	12008	[opt1] IPCP: rec'd Terminate Request #3 (Opened)
Mar 31 20:25:07	kernel		pppoe0: promiscuous mode enabled
Mar 31 20:25:07	SnortStartup	5730	Snort START for pppoe(pppoe0)...
Mar 31 20:25:07	php-fpm	95633	/rc.start_packages: Restarting/Starting all packages.
Mar 31 20:25:06	check_reload_status	381	Starting packages
Mar 31 20:25:06	php-fpm	344	/rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 192.168.78.2 -> 192.168.78.2 - Restarting packages.
Mar 31 20:25:04	php-fpm	344	/rc.newwanip: Creating rrd update script
Mar 31 20:25:04	php-fpm	344	/rc.newwanip: Resyncing OpenVPN instances for interface OPT1.
Mar 31 20:25:00	php-fpm	344	/rc.newwanip: rc.newwanip: on (IP address: 192.168.78.2) (interface: OPT1[opt1]) (real interface: pppoe0).
Mar 31 20:25:00	php-fpm	344	/rc.newwanip: rc.newwanip: Info: starting on pppoe0.
Mar 31 20:24:59	ppp	12008	[opt1] IFACE: Rename interface ng0 to pppoe0
Mar 31 20:24:59	ppp	12008	[opt1] IFACE: Up event
Mar 31 20:24:59	check_reload_status	381	rc.newwanip starting pppoe0
Mar 31 20:24:58	check_reload_status	381	Rewriting resolv.conf
Mar 31 20:24:58	ppp	12008	[opt1] 192.168.78.2 -> 192.168.77.1

snort start correctly, does not matter if i stop the pppoe server or i stop the pppoe client
but as you can see " IFACE Rename interface ng0 to pppoe" is present
this is mpd5 doing
it's not snort at fault here, you should investigate why the pppoe interface disappear leadig snort to stop working, and i don't think it's the only problem you will get from it
the test was done under pfSense 2.5.0, maybe i will try tomorrow with a new vm with 2.4.5

fireodo

@kiokoman said in Snort not restart on interface:

the more i think about it the more i find it strange
it's not snort at fault here, you should investigate why the pppoe interface disappear leadig snort to stop working, and i don't think it's the only problem you will get from it

I'll keep an eye on it!

the test was done under pfSense 2.5.0, maybe i will try tomorrow with a new vm with 2.4.5

OK, lets see what happends

Thanks for your effort!
fireodo

bmeeks

@kiokoman, thank you for the testing. I too am intrigued by why the interface disappears. That will obviously confuse Snort when it can't find the interface it is configured to sniff.

Initially I thought Snort was just a victim here, but I decided to look into other possibilities. However, that search and my own testing led me to think Snort is not really at fault here.

kiokoman

ok tested it today with a vm 2.4.5, same results
no problem when i stop the pppoe server or the client, must be something on your environment,or some special event that i can't replicate. did you set any particular settings for your pppoe connection? system tunable ?

fireodo

@kiokoman said in Snort not restart on interface:

ok tested it today with a vm 2.4.5, same results
no problem when i stop the pppoe server or the client, must be something on your environment, did you set any particular settings for your pppoe connection? system tunable ?

Nothing special - only the credentials necessary for provider. I dont use a pppoe server only a client. When I restart here the "wan" (pppoe) there is no problem - the problem occurs when by any circumstances the modem loose sync/or power.

DSLAM(provider)------>(my)DSL-Modem ------> pfsense (pppoe client) ------> LAN

kiokoman

yes , the pppoe server is used by me on another pfsense to simulate a provider for another vm with pfsense 2.4.5
so if i stop the pppoe server is like as you turn off your dsl modem
wan ->pfsense (pppoe server) --> another pfsense (pppoe client) -> lan