Pfsense random restarting issues



  • 2.1-RELEASE (i386)
    built on Wed Sep 11 18:16:50 EDT 2013
    FreeBSD jsbfw1.workgroup 8.3-RELEASE-p11 FreeBSD 8.3-RELEASE-p11 #1: Wed Sep 11 18:47:57 EDT 2013 root@snapshots-8_3-i386.builders.pfsense.org:/usr/obj.pfSense/usr/pfSensesrc/src/sys/pfSense_SMP.8 i386

    It seems that my psense will restart itself at random. the server will not reboot, but the app restarts. i have checked the system log and cannot see anything that would cause it to do this.

    Does anyone have a suggestion on how to find the culprit that is causing this restart?

    snippet of log when it restarted.

    Jan 12 01:01:00 jsbfw1 php: rc.dyndns.update: phpDynDNS (jbcompsys.dnsalias.com): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
    Jan 12 12:30:01 jsbfw1 php: rc.update_urltables: /etc/rc.update_urltables: Starting up.
    Jan 12 12:30:01 jsbfw1 php: rc.update_urltables: /etc/rc.update_urltables: Sleeping for 27 seconds.
    Jan 12 12:30:28 jsbfw1 php: rc.update_urltables: /etc/rc.update_urltables: Starting URL table alias updates
    Jan 12 12:30:28 jsbfw1 php: rc.update_urltables: /etc/rc.update_urltables: pfBlockernetherlands does not need updated.
    Jan 12 12:30:28 jsbfw1 php: rc.update_urltables: /etc/rc.update_urltables: pfBlockerchina does not need updated.
    Jan 12 12:30:28 jsbfw1 php: rc.update_urltables: /etc/rc.update_urltables: pfBlockervietnam does not need updated.
    Jan 12 12:30:28 jsbfw1 php: rc.update_urltables: /etc/rc.update_urltables: pfBlockerrussia does not need updated.

    *** this is when it rebooted ****
    Jan 12 12:30:28 jsbfw1 php: rc.update_urltables: /etc/rc.update_urltables: pfBlockerspiders does not need updated.
    Jan 12 12:30:28 jsbfw1 php: rc.update_urltables: /etc/rc.update_urltables: pfBlockerwebexploits does not need updated.
    Jan 12 14:06:53 jsbfw1 check_reload_status: Linkup starting fxp0
    Jan 12 14:06:53 jsbfw1 kernel: fxp0: link state changed to DOWN
    Jan 12 14:06:55 jsbfw1 check_reload_status: Linkup starting fxp0

    Jan 12 14:06:55 jsbfw1 kernel: fxp0: link state changed to UP
    Jan 12 14:07:11 jsbfw1 check_reload_status: updating dyndns WAN_PPPOE
    Jan 12 14:07:11 jsbfw1 check_reload_status: Restarting ipsec tunnels
    Jan 12 14:07:11 jsbfw1 check_reload_status: Restarting OpenVPN tunnels/interfaces
    Jan 12 14:07:11 jsbfw1 check_reload_status: Reloading filter
    Jan 12 14:07:15 jsbfw1 php: rc.dyndns.update: phpDynDNS (jbcompsys.dnsalias.com): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
    Jan 12 14:07:20 jsbfw1 ppp: [wan_link0] LCP: no reply to 1 echo request(s)
    Jan 12 14:07:30 jsbfw1 ppp: [wan_link0] LCP: no reply to 2 echo request(s)
    Jan 12 14:07:40 jsbfw1 ppp: [wan_link0] LCP: no reply to 3 echo request(s)
    Jan 12 14:07:50 jsbfw1 check_reload_status: Linkup starting fxp0
    Jan 12 14:07:50 jsbfw1 kernel: fxp0: link state changed to DOWN
    Jan 12 14:07:50 jsbfw1 ppp: [wan_link0] LCP: no reply to 4 echo request(s)
    Jan 12 14:07:52 jsbfw1 check_reload_status: Linkup starting fxp0
    Jan 12 14:07:52 jsbfw1 kernel: fxp0: link state changed to UP
    Jan 12 14:08:00 jsbfw1 ppp: [wan_link0] LCP: no reply to 5 echo request(s)
    Jan 12 14:08:00 jsbfw1 ppp: [wan_link0] LCP: peer not responding to echo requests
    Jan 12 14:08:00 jsbfw1 ppp: [wan_link0] LCP: state change Opened –> Stopping
    Jan 12 14:08:00 jsbfw1 ppp: [wan_link0] Link: Leave bundle "wan"
    Jan 12 14:08:00 jsbfw1 ppp: [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps
    Jan 12 14:08:00 jsbfw1 ppp: [wan] IPCP: Close event
    Jan 12 14:08:00 jsbfw1 ppp: [wan] IPCP: state change Opened –> Closing
    Jan 12 14:08:00 jsbfw1 ppp: [wan] IPCP: SendTerminateReq #12
    Jan 12 14:08:00 jsbfw1 ppp: [wan] IPCP: LayerDown
    Jan 12 14:08:00 jsbfw1 ppp: [wan] IFACE: Down event
    Jan 12 14:08:00 jsbfw1 ppp: [wan] IFACE: Rename interface pppoe0 to pppoe0
    Jan 12 14:08:00 jsbfw1 ppp: [wan] IPV6CP: Close event
    Jan 12 14:08:00 jsbfw1 ppp: [wan] IPV6CP: state change Stopped –> Closed
    Jan 12 14:08:00 jsbfw1 ppp: [wan] IPCP: Down event
    Jan 12 14:08:00 jsbfw1 ppp: [wan] IPCP: LayerFinish
    Jan 12 14:08:00 jsbfw1 ppp: [wan] Bundle: No NCPs left. Closing links…
    Jan 12 14:08:00 jsbfw1 ppp: [wan] IPCP: state change Closing –> Initial
    Jan 12 14:08:00 jsbfw1 ppp: [wan] IPV6CP: Down event
    Jan 12 14:08:00 jsbfw1 ppp: [wan] IPV6CP: state change Closed –> Initial
    Jan 12 14:08:00 jsbfw1 ppp: [wan_link0] LCP: SendTerminateReq #8
    Jan 12 14:08:00 jsbfw1 ppp: [wan_link0] LCP: LayerDown
    Jan 12 14:08:00 jsbfw1 check_reload_status: Rewriting resolv.conf
    Jan 12 14:08:02 jsbfw1 ppp: [wan_link0] LCP: SendTerminateReq #9
    Jan 12 14:08:04 jsbfw1 ppp: [wan_link0] LCP: state change Stopping –> Stopped
    Jan 12 14:08:04 jsbfw1 ppp: [wan_link0] LCP: LayerFinish
    Jan 12 14:08:04 jsbfw1 ppp: [wan_link0] PPPoE: connection closed
    Jan 12 14:08:04 jsbfw1 ppp: [wan_link0] Link: DOWN event
    Jan 12 14:08:04 jsbfw1 ppp: [wan_link0] LCP: Down event
    Jan 12 14:08:04 jsbfw1 ppp: [wan_link0] LCP: state change Stopped –> Starting
    Jan 12 14:08:04 jsbfw1 ppp: [wan_link0] LCP: LayerStart
    Jan 12 14:08:04 jsbfw1 ppp: [wan_link0] Link: reconnection attempt 1 in 1 seconds
    Jan 12 14:08:05 jsbfw1 ppp: [wan_link0] Link: reconnection attempt 1
    Jan 12 14:08:05 jsbfw1 ppp: [wan_link0] PPPoE: Connecting to ''
    Jan 12 14:08:14 jsbfw1 ppp: [wan_link0] PPPoE connection timeout after 9 seconds
    Jan 12 14:08:14 jsbfw1 ppp: [wan_link0] Link: DOWN event
    Jan 12 14:08:14 jsbfw1 ppp: [wan_link0] LCP: Down event
    Jan 12 14:08:14 jsbfw1 ppp: [wan_link0] Link: reconnection attempt 2 in 4 seconds
    Jan 12 14:08:18 jsbfw1 ppp: [wan_link0] Link: reconnection attempt 2
    Jan 12 14:08:18 jsbfw1 ppp: [wan_link0] PPPoE: Connecting to ''
    Jan 12 14:08:27 jsbfw1 ppp: [wan_link0] PPPoE connection timeout after 9 seconds
    Jan 12 14:08:27 jsbfw1 ppp: [wan_link0] Link: DOWN event
    Jan 12 14:08:27 jsbfw1 ppp: [wan_link0] LCP: Down event
    Jan 12 14:08:27 jsbfw1 ppp: [wan_link0] Link: reconnection attempt 3 in 3 seconds
    Jan 12 14:08:30 jsbfw1 ppp: [wan_link0] Link: reconnection attempt 3
    Jan 12 14:08:30 jsbfw1 ppp: [wan_link0] PPPoE: Connecting to ''
    Jan 12 14:08:39 jsbfw1 ppp: [wan_link0] PPPoE connection timeout after 9 seconds
    Jan 12 14:08:39 jsbfw1 ppp: [wan_link0] Link: DOWN event
    Jan 12 14:08:39 jsbfw1 ppp: [wan_link0] LCP: Down event
    Jan 12 14:08:39 jsbfw1 ppp: [wan_link0] Link: reconnection attempt 4 in 3 seconds
    Jan 12 14:08:42 jsbfw1 ppp: [wan_link0] Link: reconnection attempt 4
    Jan 12 14:08:42 jsbfw1 ppp: [wan_link0] PPPoE: Connecting to ''
    Jan 12 14:08:51 jsbfw1 ppp: [wan_link0] PPPoE connection timeout after 9 seconds
    Jan 12 14:08:51 jsbfw1 ppp: [wan_link0] Link: DOWN event
    Jan 12 14:08:51 jsbfw1 ppp: [wan_link0] LCP: Down event
    Jan 12 14:08:51 jsbfw1 ppp: [wan_link0] Link: reconnection attempt 5 in 2 seconds
    Jan 12 14:08:53 jsbfw1 ppp: [wan_link0] Link: reconnection attempt 5
    Jan 12 14:08:53 jsbfw1 ppp: [wan_link0] PPPoE: Connecting to ''
    Jan 12 14:09:02 jsbfw1 ppp: [wan_link0] PPPoE connection timeout after 9 seconds
    Jan 12 14:09:02 jsbfw1 ppp: [wan_link0] Link: DOWN event
    Jan 12 14:09:02 jsbfw1 ppp: [wan_link0] LCP: Down event
    Jan 12 14:09:02 jsbfw1 ppp: [wan_link0] Link: reconnection attempt 6 in 1 seconds
    Jan 12 14:09:03 jsbfw1 ppp: [wan_link0] Link: reconnection attempt 6
    Jan 12 14:09:03 jsbfw1 ppp: [wan_link0] PPPoE: Connecting to ''
    Jan 12 14:09:09 jsbfw1 ppp: PPPoE: rec'd ACNAME "bas2-toronto29"
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0] PPPoE: connection successful
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0] Link: UP event
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0] LCP: Up event
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0] LCP: state change Starting –> Req-Sent
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0] LCP: SendConfigReq #10
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0]  PROTOCOMP
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0]  MRU 1492
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0]  MAGICNUM 3aaac2a2
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0] LCP: rec'd Configure Request #202 (Req-Sent)
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0]  MRU 1492
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0]  AUTHPROTO PAP
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0]  MAGICNUM 5a105f39
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0] LCP: SendConfigAck #202
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0]  MRU 1492
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0]  AUTHPROTO PAP
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0]  MAGICNUM 5a105f39
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0] LCP: state change Req-Sent –> Ack-Sent
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0] LCP: rec'd Configure Ack #10 (Ack-Sent)
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0]  PROTOCOMP
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0]  MRU 1492
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0]  MAGICNUM 3aaac2a2
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0] LCP: state change Ack-Sent –> Opened
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0] LCP: auth: peer wants PAP, I want nothing
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0] PAP: using authname "b1rgbv22"
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0] PAP: sending REQUEST #1 len: 23
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0] LCP: LayerUp
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0] PAP: rec'd ACK #1 len: 5
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0] LCP: authorization successful
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0] Link: Matched action 'bundle "wan" ""'
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0] Link: Join bundle "wan"
    Jan 12 14:09:10 jsbfw1 ppp: [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPCP: Open event
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPCP: state change Initial –> Starting
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPCP: LayerStart
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPV6CP: Open event
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPV6CP: state change Initial –> Starting
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPV6CP: LayerStart
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPCP: Up event
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPCP: state change Starting –> Req-Sent
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPCP: SendConfigReq #13
    Jan 12 14:09:10 jsbfw1 ppp: [wan]  IPADDR 0.0.0.0
    Jan 12 14:09:10 jsbfw1 ppp: [wan]  COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPV6CP: Up event
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPV6CP: state change Starting –> Req-Sent
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPV6CP: SendConfigReq #4
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0] LCP: rec'd Protocol Reject #203 (Opened)
    Jan 12 14:09:10 jsbfw1 ppp: [wan_link0] LCP: protocol IPV6CP was rejected
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPV6CP: protocol was rejected by peer
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPV6CP: state change Req-Sent –> Stopped
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPV6CP: LayerFinish
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPCP: rec'd Configure Request #249 (Req-Sent)
    Jan 12 14:09:10 jsbfw1 ppp: [wan]  IPADDR 64.230.200.164
    Jan 12 14:09:10 jsbfw1 ppp: [wan]    64.230.200.164 is OK
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPCP: SendConfigAck #249
    Jan 12 14:09:10 jsbfw1 ppp: [wan]  IPADDR 64.230.200.164
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPCP: state change Req-Sent –> Ack-Sent
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPCP: rec'd Configure Reject #13 (Ack-Sent)
    Jan 12 14:09:10 jsbfw1 ppp: [wan]  COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPCP: SendConfigReq #14
    Jan 12 14:09:10 jsbfw1 ppp: [wan]  IPADDR 0.0.0.0
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPCP: rec'd Configure Nak #14 (Ack-Sent)
    Jan 12 14:09:10 jsbfw1 ppp: [wan]  IPADDR 76.69.119.217
    Jan 12 14:09:10 jsbfw1 ppp: [wan]    76.69.119.217 is OK
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPCP: SendConfigReq #15
    Jan 12 14:09:10 jsbfw1 ppp: [wan]  IPADDR 76.69.119.217
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPCP: rec'd Configure Ack #15 (Ack-Sent)
    Jan 12 14:09:10 jsbfw1 ppp: [wan]  IPADDR 76.69.119.217
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPCP: state change Ack-Sent –> Opened
    Jan 12 14:09:10 jsbfw1 ppp: [wan] IPCP: LayerUp
    Jan 12 14:09:10 jsbfw1 ppp: [wan]  76.69.119.217 -> 64.230.200.164
    Jan 12 14:09:10 jsbfw1 check_reload_status: rc.newwanip starting pppoe0
    Jan 12 14:09:11 jsbfw1 ppp: [wan] IFACE: Up event
    Jan 12 14:09:11 jsbfw1 ppp: [wan] IFACE: Rename interface ng0 to pppoe0
    Jan 12 14:09:13 jsbfw1 php: rc.newwanip: rc.newwanip: Informational is starting pppoe0.


  • Netgate Administrator

    What makes you think something restarted? It looks like your WAN went down and then came back up.

    Since fxp0 also seems to have gone down it looks like your modem rebooted. Overheated perhaps? Bad power supply?

    Steve



  • Maybe unrelated but check apinger logs.

    I had once a situation where connection stayed up but the gateway did not respond in time.
    Causing pfSense to reload its rules causing unwanted outages.

    You can adjust apinger treshold if needed.

    Good luck

    Peter


Log in to reply