3G WAN link does not re-connect automatically (2.0.1, Huawei E367)
-
My pfSense has a 3G USB dongle (Huawei E367) configured for fall-back routing. If the ADSL lines fail, then the 3G dongle can take over. This works OK in testing, when I force the failover by unplugging the ADSL lines.
Every day or so, the 3G link will drop (when the ISP has a short outage?). pfSense tries to re-connect, but it gives up and marks the 3G PPP interface as Down.
Later from the pfSense GUI, "Status / Interfaces" will show:
3G_DONGLE interface (ppp0)
Status downIf I click the Connect button, the 3G link comes back up OK.
How can I configure pfSense to re-connect automatically?
PS: In case it helps, here are the lines from my firewall log, relating to the opt3 (3G PPP) interface. First, there is an example of a good connection setup. Then, there is the most recent failure to re-establish the link. What concerns me is not the failure, but the fact that pfSense does not try again after perhaps 5 or 10 minutes.
Thanks!
Jan 13 10:21:17 217.169.18.161 ppp: [opt3] IFACE: Close event
Jan 13 10:21:17 217.169.18.161 ppp: [opt3] IPCP: Close event
Jan 13 10:21:19 217.169.18.161 ppp: [opt3] Bundle: Shutdown
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] Link: Shutdown
Jan 13 10:21:19 217.169.18.161 ppp: [opt3] Bundle: Interface ng1 created
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] Link: OPEN event
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] LCP: Open event
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] LCP: state change Initial –> Starting
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] LCP: LayerStart
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] chat: Detected Hayes compatible modem.
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] chat: Dialing server at *99#…
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] chat: Connected at 28800000.
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] MODEM: chat script succeeded
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] Link: UP event
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] LCP: Up event
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] LCP: state change Starting –> Req-Sent
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] LCP: SendConfigReq #1
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] ACFCOMP
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] PROTOCOMP
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] ACCMAP 0x000a0000
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] MRU 1500
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] MAGICNUM 7716623f
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] LCP: rec'd Configure Request #10 (Req-Sent)
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] ACCMAP 0x00000000
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] AUTHPROTO CHAP MD5
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] MAGICNUM 219e0ed3
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] PROTOCOMP
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] ACFCOMP
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] LCP: SendConfigAck #10
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] ACCMAP 0x00000000
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] AUTHPROTO CHAP MD5
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] MAGICNUM 219e0ed3
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] PROTOCOMP
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] ACFCOMP
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] LCP: state change Req-Sent –> Ack-Sent
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] LCP: rec'd Configure Ack #1 (Ack-Sent)
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] ACFCOMP
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] PROTOCOMP
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] ACCMAP 0x000a0000
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] MRU 1500
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] MAGICNUM 7716623f
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] LCP: state change Ack-Sent –> Opened
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] LCP: auth: peer wants CHAP, I want nothing
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] LCP: LayerUp
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] LCP: rec'd Discard Request #11 (Opened)
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] CHAP: rec'd CHALLENGE #1 len: 35
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] Name: "UMTS_CHAP_SRVR"
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] CHAP: Using authname "user"
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] CHAP: sending RESPONSE #1 len: 25
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] CHAP: rec'd SUCCESS #1 len: 4
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] LCP: authorization successful
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] Link: Matched action 'bundle "opt3" ""'
Jan 13 10:21:19 217.169.18.161 ppp: [opt3_link0] Link: Join bundle "opt3"
Jan 13 10:21:19 217.169.18.161 ppp: [opt3] Bundle: Status update: up 1 link, total bandwidth 28800000 bps
Jan 13 10:21:19 217.169.18.161 ppp: [opt3] IPCP: Open event
Jan 13 10:21:19 217.169.18.161 ppp: [opt3] IPCP: state change Initial –> Starting
Jan 13 10:21:19 217.169.18.161 ppp: [opt3] IPCP: LayerStart
Jan 13 10:21:19 217.169.18.161 ppp: [opt3] IPCP: Up event
Jan 13 10:21:19 217.169.18.161 ppp: [opt3] IPCP: state change Starting –> Req-Sent
Jan 13 10:21:19 217.169.18.161 ppp: [opt3] IPCP: SendConfigReq #1
Jan 13 10:21:19 217.169.18.161 ppp: [opt3] IPADDR 0.0.0.0
Jan 13 10:21:19 217.169.18.161 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jan 13 10:21:20 217.169.18.161 ppp: [opt3] IPCP: rec'd Configure Nak #1 (Req-Sent)
Jan 13 10:21:20 217.169.18.161 ppp: [opt3] PRIDNS 10.11.12.13
Jan 13 10:21:20 217.169.18.161 ppp: [opt3] SECDNS 10.11.12.14
Jan 13 10:21:20 217.169.18.161 ppp: [opt3] IPCP: SendConfigReq #2
Jan 13 10:21:20 217.169.18.161 ppp: [opt3] IPADDR 0.0.0.0
Jan 13 10:21:20 217.169.18.161 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jan 13 10:21:20 217.169.18.161 ppp: [opt3] IPCP: rec'd Configure Request #2 (Req-Sent)
Jan 13 10:21:20 217.169.18.161 ppp: [opt3] IPCP: SendConfigAck #2
Jan 13 10:21:20 217.169.18.161 ppp: [opt3] IPCP: state change Req-Sent –> Ack-Sent
Jan 13 10:21:20 217.169.18.161 ppp: [opt3] IPCP: rec'd Configure Reject #2 (Ack-Sent)
Jan 13 10:21:20 217.169.18.161 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jan 13 10:21:20 217.169.18.161 ppp: [opt3] IPCP: SendConfigReq #3
Jan 13 10:21:20 217.169.18.161 ppp: [opt3] IPADDR 0.0.0.0
Jan 13 10:21:20 217.169.18.161 ppp: [opt3] IPCP: rec'd Configure Nak #3 (Ack-Sent)
Jan 13 10:21:20 217.169.18.161 ppp: [opt3] IPADDR 81.187.44.56
Jan 13 10:21:20 217.169.18.161 ppp: [opt3] 81.187.44.56 is OK
Jan 13 10:21:20 217.169.18.161 ppp: [opt3] IPCP: SendConfigReq #4
Jan 13 10:21:20 217.169.18.161 ppp: [opt3] IPADDR 81.187.44.56
Jan 13 10:21:20 217.169.18.161 ppp: [opt3] IPCP: rec'd Configure Ack #4 (Ack-Sent)
Jan 13 10:21:20 217.169.18.161 ppp: [opt3] IPADDR 81.187.44.56
Jan 13 10:21:20 217.169.18.161 ppp: [opt3] IPCP: state change Ack-Sent –> Opened
Jan 13 10:21:20 217.169.18.161 ppp: [opt3] IPCP: LayerUp
Jan 13 10:21:20 217.169.18.161 ppp: [opt3] 81.187.44.56 -> 10.64.64.1
Jan 13 10:21:21 217.169.18.161 ppp: [opt3] IFACE: Up event
Jan 13 10:21:27 217.169.18.161 php: : rc.newwanip: on (IP address: 81.187.44.56) (interface: opt3) (real interface: ppp0).
Jan 13 11:02:12 217.169.18.161 ppp: [opt3_link0] LCP: rec'd Terminate Request #12 (Opened)
Jan 13 11:02:12 217.169.18.161 ppp: [opt3_link0] LCP: state change Opened –> Stopping
Jan 13 11:02:12 217.169.18.161 ppp: [opt3_link0] Link: Leave bundle "opt3"
Jan 13 11:02:12 217.169.18.161 ppp: [opt3] Bundle: Status update: up 0 links, total bandwidth 9600 bps
Jan 13 11:02:12 217.169.18.161 ppp: [opt3] IPCP: Close event
Jan 13 11:02:12 217.169.18.161 ppp: [opt3] IPCP: state change Opened –> Closing
Jan 13 11:02:12 217.169.18.161 ppp: [opt3] IPCP: SendTerminateReq #5
Jan 13 11:02:12 217.169.18.161 ppp: [opt3] IPCP: LayerDown
Jan 13 11:02:12 217.169.18.161 ppp: [opt3] IFACE: Down event
Jan 13 11:02:13 217.169.18.161 ppp: [opt3] IPCP: Down event
Jan 13 11:02:13 217.169.18.161 ppp: [opt3] IPCP: LayerFinish
Jan 13 11:02:13 217.169.18.161 ppp: [opt3] Bundle: No NCPs left. Closing links…
Jan 13 11:02:13 217.169.18.161 ppp: [opt3] IPCP: state change Closing –> Initial
Jan 13 11:02:13 217.169.18.161 ppp: [opt3_link0] LCP: SendTerminateAck #2
Jan 13 11:02:13 217.169.18.161 ppp: [opt3_link0] LCP: LayerDown
Jan 13 11:02:15 217.169.18.161 ppp: [opt3_link0] LCP: state change Stopping –> Stopped
Jan 13 11:02:15 217.169.18.161 ppp: [opt3_link0] LCP: LayerFinish
Jan 13 11:02:15 217.169.18.161 ppp: [opt3_link0] Link: DOWN event
Jan 13 11:02:15 217.169.18.161 ppp: [opt3_link0] LCP: Down event
Jan 13 11:02:15 217.169.18.161 ppp: [opt3_link0] LCP: state change Stopped –> Starting
Jan 13 11:02:15 217.169.18.161 ppp: [opt3_link0] LCP: LayerStart
Jan 13 11:02:15 217.169.18.161 ppp: [opt3_link0] Link: reconnection attempt 1 in 4 seconds
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] Link: reconnection attempt 1
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] chat: Detected Hayes compatible modem.
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] chat: Dialing server at *99#…
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] chat: Connected at 28800000.
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] MODEM: chat script succeeded
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] Link: UP event
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] LCP: Up event
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] LCP: state change Starting –> Req-Sent
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] LCP: SendConfigReq #3
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] ACFCOMP
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] PROTOCOMP
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] ACCMAP 0x000a0000
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] MRU 1500
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] MAGICNUM af2b418d
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] LCP: rec'd Configure Request #13 (Req-Sent)
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] ACCMAP 0x00000000
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] AUTHPROTO CHAP MD5
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] MAGICNUM 21c39719
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] PROTOCOMP
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] ACFCOMP
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] LCP: SendConfigAck #13
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] ACCMAP 0x00000000
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] AUTHPROTO CHAP MD5
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] MAGICNUM 21c39719
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] PROTOCOMP
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] ACFCOMP
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] LCP: state change Req-Sent –> Ack-Sent
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] LCP: rec'd Configure Ack #3 (Ack-Sent)
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] ACFCOMP
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] PROTOCOMP
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] ACCMAP 0x000a0000
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] MRU 1500
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] MAGICNUM af2b418d
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] LCP: state change Ack-Sent –> Opened
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] LCP: auth: peer wants CHAP, I want nothing
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] LCP: LayerUp
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] LCP: rec'd Discard Request #14 (Opened)
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] CHAP: rec'd CHALLENGE #1 len: 35
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] Name: "UMTS_CHAP_SRVR"
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] CHAP: Using authname "user"
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] CHAP: sending RESPONSE #1 len: 25
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] CHAP: rec'd SUCCESS #1 len: 4
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] LCP: authorization successful
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] Link: Matched action 'bundle "opt3" ""'
Jan 13 11:02:19 217.169.18.161 ppp: [opt3_link0] Link: Join bundle "opt3"
Jan 13 11:02:19 217.169.18.161 ppp: [opt3] Bundle: Status update: up 1 link, total bandwidth 28800000 bps
Jan 13 11:02:19 217.169.18.161 ppp: [opt3] IPCP: Open event
Jan 13 11:02:19 217.169.18.161 ppp: [opt3] IPCP: state change Initial –> Starting
Jan 13 11:02:19 217.169.18.161 ppp: [opt3] IPCP: LayerStart
Jan 13 11:02:19 217.169.18.161 ppp: [opt3] IPCP: Up event
Jan 13 11:02:19 217.169.18.161 ppp: [opt3] IPCP: state change Starting –> Req-Sent
Jan 13 11:02:19 217.169.18.161 ppp: [opt3] IPCP: SendConfigReq #6
Jan 13 11:02:19 217.169.18.161 ppp: [opt3] IPADDR 0.0.0.0
Jan 13 11:02:19 217.169.18.161 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jan 13 11:02:20 217.169.18.161 ppp: [opt3] IPCP: rec'd Configure Nak #6 (Req-Sent)
Jan 13 11:02:20 217.169.18.161 ppp: [opt3] PRIDNS 10.11.12.13
Jan 13 11:02:20 217.169.18.161 ppp: [opt3] SECDNS 10.11.12.14
Jan 13 11:02:20 217.169.18.161 ppp: [opt3] IPCP: SendConfigReq #7
Jan 13 11:02:20 217.169.18.161 ppp: [opt3] IPADDR 0.0.0.0
Jan 13 11:02:20 217.169.18.161 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jan 13 11:02:21 217.169.18.161 ppp: [opt3] IPCP: rec'd Configure Nak #7 (Req-Sent)
Jan 13 11:02:21 217.169.18.161 ppp: [opt3] PRIDNS 10.11.12.13
Jan 13 11:02:21 217.169.18.161 ppp: [opt3] SECDNS 10.11.12.14
Jan 13 11:02:21 217.169.18.161 ppp: [opt3] IPCP: SendConfigReq #8
Jan 13 11:02:21 217.169.18.161 ppp: [opt3] IPADDR 0.0.0.0
Jan 13 11:02:21 217.169.18.161 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jan 13 11:02:22 217.169.18.161 ppp: [opt3] IPCP: rec'd Configure Nak #8 (Req-Sent)
Jan 13 11:02:22 217.169.18.161 ppp: [opt3] PRIDNS 10.11.12.13
Jan 13 11:02:22 217.169.18.161 ppp: [opt3] SECDNS 10.11.12.14
Jan 13 11:02:22 217.169.18.161 ppp: [opt3] IPCP: SendConfigReq #9
Jan 13 11:02:22 217.169.18.161 ppp: [opt3] IPADDR 0.0.0.0
Jan 13 11:02:22 217.169.18.161 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jan 13 11:02:23 217.169.18.161 ppp: [opt3] IPCP: rec'd Configure Nak #9 (Req-Sent)
Jan 13 11:02:23 217.169.18.161 ppp: [opt3] PRIDNS 10.11.12.13
Jan 13 11:02:23 217.169.18.161 ppp: [opt3] SECDNS 10.11.12.14
Jan 13 11:02:23 217.169.18.161 ppp: [opt3] IPCP: SendConfigReq #10
Jan 13 11:02:23 217.169.18.161 ppp: [opt3] IPADDR 0.0.0.0
Jan 13 11:02:23 217.169.18.161 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jan 13 11:02:24 217.169.18.161 ppp: [opt3] IPCP: rec'd Configure Nak #10 (Req-Sent)
Jan 13 11:02:24 217.169.18.161 ppp: [opt3] PRIDNS 10.11.12.13
Jan 13 11:02:24 217.169.18.161 ppp: [opt3] SECDNS 10.11.12.14
Jan 13 11:02:24 217.169.18.161 ppp: [opt3] IPCP: SendConfigReq #11
Jan 13 11:02:24 217.169.18.161 ppp: [opt3] IPADDR 0.0.0.0
Jan 13 11:02:24 217.169.18.161 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jan 13 11:02:25 217.169.18.161 ppp: [opt3] IPCP: rec'd Configure Nak #11 (Req-Sent)
Jan 13 11:02:25 217.169.18.161 ppp: [opt3] PRIDNS 10.11.12.13
Jan 13 11:02:25 217.169.18.161 ppp: [opt3] SECDNS 10.11.12.14
Jan 13 11:02:25 217.169.18.161 ppp: [opt3] IPCP: SendConfigReq #12
Jan 13 11:02:25 217.169.18.161 ppp: [opt3] IPADDR 0.0.0.0
Jan 13 11:02:25 217.169.18.161 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jan 13 11:02:26 217.169.18.161 ppp: [opt3] IPCP: rec'd Configure Nak #12 (Req-Sent)
Jan 13 11:02:26 217.169.18.161 ppp: [opt3] PRIDNS 10.11.12.13
Jan 13 11:02:26 217.169.18.161 ppp: [opt3] SECDNS 10.11.12.14
Jan 13 11:02:26 217.169.18.161 ppp: [opt3] IPCP: SendConfigReq #13
Jan 13 11:02:26 217.169.18.161 ppp: [opt3] IPADDR 0.0.0.0
Jan 13 11:02:26 217.169.18.161 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jan 13 11:02:27 217.169.18.161 ppp: [opt3] IPCP: rec'd Configure Nak #13 (Req-Sent)
Jan 13 11:02:27 217.169.18.161 ppp: [opt3] PRIDNS 10.11.12.13
Jan 13 11:02:27 217.169.18.161 ppp: [opt3] SECDNS 10.11.12.14
Jan 13 11:02:27 217.169.18.161 ppp: [opt3] IPCP: SendConfigReq #14
Jan 13 11:02:27 217.169.18.161 ppp: [opt3] IPADDR 0.0.0.0
Jan 13 11:02:27 217.169.18.161 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jan 13 11:02:28 217.169.18.161 ppp: [opt3] IPCP: rec'd Configure Nak #14 (Req-Sent)
Jan 13 11:02:28 217.169.18.161 ppp: [opt3] PRIDNS 10.11.12.13
Jan 13 11:02:28 217.169.18.161 ppp: [opt3] SECDNS 10.11.12.14
Jan 13 11:02:28 217.169.18.161 ppp: [opt3] IPCP: SendConfigReq #15
Jan 13 11:02:28 217.169.18.161 ppp: [opt3] IPADDR 0.0.0.0
Jan 13 11:02:28 217.169.18.161 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jan 13 11:02:29 217.169.18.161 ppp: [opt3] IPCP: rec'd Configure Nak #15 (Req-Sent)
Jan 13 11:02:29 217.169.18.161 ppp: [opt3] PRIDNS 10.11.12.13
Jan 13 11:02:29 217.169.18.161 ppp: [opt3] SECDNS 10.11.12.14
Jan 13 11:02:29 217.169.18.161 ppp: [opt3] IPCP: not converging
Jan 13 11:02:29 217.169.18.161 ppp: [opt3] IPCP: parameter negotiation failed
Jan 13 11:02:29 217.169.18.161 ppp: [opt3] IPCP: state change Req-Sent –> Stopped
Jan 13 11:02:29 217.169.18.161 ppp: [opt3] IPCP: LayerFinish
Jan 13 11:02:29 217.169.18.161 ppp: [opt3] Bundle: No NCPs left. Closing links…
Jan 13 11:02:29 217.169.18.161 ppp: [opt3] Bundle: closing link "opt3_link0"…
Jan 13 11:02:29 217.169.18.161 ppp: [opt3_link0] Link: CLOSE event
Jan 13 11:02:29 217.169.18.161 ppp: [opt3_link0] LCP: Close event
Jan 13 11:02:29 217.169.18.161 ppp: [opt3_link0] LCP: state change Opened –> Closing
Jan 13 11:02:29 217.169.18.161 ppp: [opt3_link0] Link: Leave bundle "opt3"
Jan 13 11:02:29 217.169.18.161 ppp: [opt3] Bundle: Status update: up 0 links, total bandwidth 9600 bps
Jan 13 11:02:29 217.169.18.161 ppp: [opt3] IPCP: Close event
Jan 13 11:02:29 217.169.18.161 ppp: [opt3] IPCP: state change Stopped –> Closed
Jan 13 11:02:29 217.169.18.161 ppp: [opt3] IPCP: Down event
Jan 13 11:02:29 217.169.18.161 ppp: [opt3] IPCP: state change Closed –> Initial
Jan 13 11:02:29 217.169.18.161 ppp: [opt3_link0] LCP: SendTerminateReq #4
Jan 13 11:02:29 217.169.18.161 ppp: [opt3_link0] LCP: LayerDown
Jan 13 11:02:29 217.169.18.161 ppp: [opt3_link0] LCP: rec'd Terminate Ack #4 (Closing)
Jan 13 11:02:29 217.169.18.161 ppp: [opt3_link0] LCP: state change Closing –> Closed
Jan 13 11:02:29 217.169.18.161 ppp: [opt3_link0] LCP: LayerFinish
Jan 13 11:02:29 217.169.18.161 ppp: [opt3_link0] Link: DOWN event
Jan 13 11:02:29 217.169.18.161 ppp: [opt3_link0] LCP: Down event
Jan 13 11:02:29 217.169.18.161 ppp: [opt3_link0] LCP: state change Closed –> Initial -
I have exactly the same problem with my 3G modem (huawei k4505). (pfsense 2.0.1, but the problem also exists in 2.0)
Also after a period of uptime the PPP-connection drops and does not come up again.
In my PPP-log it also says: "IPCP: not converging".After rebooting everything comes right up again.
-
So - same problem - different 3G card.
Out of interest, can you recover without rebooting, by using the GUI "Status / Interfaces" page, and pressing "Connect" next to the 3G WAN interface that's gone down?
Cheers
- Martin
-
So - same problem - different 3G card.
Out of interest, can you recover without rebooting, by using the GUI "Status / Interfaces" page, and pressing "Connect" next to the 3G WAN interface that's gone down?
Cheers
- Martin
Not always, but sometime after hitting the disconnect / connectbutton several times, the link comes up again.
-
Same Problem here. Huawei E160e. Have some info about the correction ?.
-
This is what is happening when the huawei 3G connection is lost en never gets up again:
Looks like the USB connection of the huawei disconnects for a second and is connects again right after.
But the 3G connection never gets online again.
Do you see the same behavior?Jan 30 11:20:05 kernel: ugen3.2: <vodafone group="" (huawei)=""> at usbus3 (disconnected) Jan 30 11:20:05 kernel: u3g0: at uhub3, port 2, addr 2 (disconnected) Jan 30 11:20:05 kernel: umass1: at uhub3, port 2, addr 2 (disconnected) Jan 30 11:20:05 kernel: (cd0:umass-sim1:1:0:0): lost device Jan 30 11:20:05 kernel: (cd0:umass-sim1:1:0:0): removing device entry Jan 30 11:20:05 kernel: umass2: at uhub3, port 2, addr 2 (disconnected) Jan 30 11:20:05 kernel: (da1:umass-sim2:2:0:0): lost device Jan 30 11:20:05 kernel: (da1:umass-sim2:2:0:0): removing device entry Jan 30 11:20:06 check_reload_status: Rewriting resolv.conf Jan 30 11:20:14 kernel: ugen3.2: <vodafone group="" (huawei)=""> at usbus3 Jan 30 11:20:14 kernel: u3g0: <vodafone 0="" 2="" group="" (huawei)="" vodafone="" mobile="" broadband="" (huawei),="" class="" 0,="" rev="" 2.00="" 0.00,="" addr=""> on usbus3 Jan 30 11:20:14 kernel: u3g0: Found 4 ports. Jan 30 11:20:14 kernel: umass1: <vodafone 0="" 2="" group="" (huawei)="" vodafone="" mobile="" broadband="" (huawei),="" class="" 0,="" rev="" 2.00="" 0.00,="" addr=""> on usbus3 Jan 30 11:20:14 kernel: umass1: SCSI over Bulk-Only; quirks = 0x0000 Jan 30 11:20:15 kernel: umass1:1:1:-1: Attached to scbus1 Jan 30 11:20:15 kernel: umass2: <vodafone 0="" 2="" group="" (huawei)="" vodafone="" mobile="" broadband="" (huawei),="" class="" 0,="" rev="" 2.00="" 0.00,="" addr=""> on usbus3 Jan 30 11:20:15 kernel: umass2: SCSI over Bulk-Only; quirks = 0x0000 Jan 30 11:20:16 kernel: (probe0:umass-sim1:1:0:0): TEST UNIT READY. CDB: 0 0 0 0 0 0 Jan 30 11:20:16 kernel: (probe0:umass-sim1:1:0:0): CAM status: SCSI Status Error Jan 30 11:20:16 kernel: (probe0:umass-sim1:1:0:0): SCSI status: Check Condition Jan 30 11:20:16 kernel: (probe0:umass-sim1:1:0:0): SCSI sense: NOT READY asc:3a,0 (Medium not present) Jan 30 11:20:16 kernel: cd0 at umass-sim1 bus 1 scbus1 target 0 lun 0 Jan 30 11:20:16 kernel: cd0: <vodafone cd="" rom="" (huawei)="" 2.31=""> Removable CD-ROM SCSI-2 device Jan 30 11:20:16 kernel: cd0: 40.000MB/s transfers Jan 30 11:20:16 kernel: cd0: Attempt to query device size failed: NOT READY, Medium not present Jan 30 11:20:16 kernel: umass2:2:2:-1: Attached to scbus2 Jan 30 11:20:17 kernel: (probe0:umass-sim2:2:0:0): TEST UNIT READY. CDB: 0 0 0 0 0 0 Jan 30 11:20:17 kernel: (probe0:umass-sim2:2:0:0): CAM status: SCSI Status Error Jan 30 11:20:17 kernel: (probe0:umass-sim2:2:0:0): SCSI status: Check Condition Jan 30 11:20:17 kernel: (probe0:umass-sim2:2:0:0): SCSI sense: NOT READY asc:3a,0 (Medium not present) Jan 30 11:20:17 kernel: da1 at umass-sim2 bus 2 scbus2 target 0 lun 0 Jan 30 11:20:17 kernel: da1: <vodafone storage="" (huawei)="" 2.31=""> Removable Direct Access SCSI-2 device Jan 30 11:20:17 kernel: da1: 40.000MB/s transfers Jan 30 11:20:17 kernel: da1: Attempt to query device size failed: NOT READY, Medium not present Jan 30 11:20:33 apinger: ALARM: UMTSBACKUP(8.8.4.4) *** UMTSBACKUPdown *** Jan 30 11:20:43 check_reload_status: Reloading filter Jan 30 11:20:48 php: : MONITOR: UMTSBACKUP is down, removing from routing group</vodafone></vodafone></vodafone></vodafone></vodafone></vodafone></vodafone>
-
That could be an issue with the hardware or USB on the box if it drops off like that. Are you using any kind of USB extension cables or hubs in between there? Or is it plugged right into the firewall?
-
That could be an issue with the hardware or USB on the box if it drops off like that. Are you using any kind of USB extension cables or hubs in between there? Or is it plugged right into the firewall?
I am using a extension cable, but I also tried to connect it right at the firewall itself on several different USB ports. This same error occurs.
But besides that. If the Modem comes up again, why does the PPP 3G connection fail to come online.
The PPP service tries to connect, it comes close (even gets an IP-address), but fails with the error below:Jan 30 11:20:23 ppp: [opt1] IPCP: rec'd Configure Nak #13 (Req-Sent) Jan 30 11:20:23 ppp: [opt1] PRIDNS 10.11.12.13 Jan 30 11:20:23 ppp: [opt1] SECDNS 10.11.12.14 Jan 30 11:20:23 ppp: [opt1] IPCP: SendConfigReq #14 Jan 30 11:20:23 ppp: [opt1] IPADDR 0.0.0.0 Jan 30 11:20:23 ppp: [opt1] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid Jan 30 11:20:24 ppp: [opt1] IPCP: rec'd Configure Nak #14 (Req-Sent) Jan 30 11:20:24 ppp: [opt1] PRIDNS 10.11.12.13 Jan 30 11:20:24 ppp: [opt1] SECDNS 10.11.12.14 Jan 30 11:20:24 ppp: [opt1] IPCP: SendConfigReq #15 Jan 30 11:20:24 ppp: [opt1] IPADDR 0.0.0.0 Jan 30 11:20:24 ppp: [opt1] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid Jan 30 11:20:25 ppp: [opt1] IPCP: rec'd Configure Request #0 (Req-Sent) Jan 30 11:20:25 ppp: [opt1] IPCP: SendConfigAck #0 Jan 30 11:20:25 ppp: [opt1] IPCP: state change Req-Sent --> Ack-Sent Jan 30 11:20:25 ppp: [opt1] IPCP: rec'd Configure Reject #15 (Ack-Sent) Jan 30 11:20:25 ppp: [opt1] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid Jan 30 11:20:25 ppp: [opt1] IPCP: SendConfigReq #16 Jan 30 11:20:25 ppp: [opt1] IPADDR 0.0.0.0 Jan 30 11:20:25 ppp: [opt1] IPCP: rec'd Configure Nak #16 (Ack-Sent) Jan 30 11:20:25 ppp: [opt1] IPADDR 10.22.77.191 Jan 30 11:20:25 ppp: [opt1] 10.22.77.191 is OK Jan 30 11:20:25 ppp: [opt1] IPCP: not converging Jan 30 11:20:25 ppp: [opt1] IPCP: parameter negotiation failed Jan 30 11:20:25 ppp: [opt1] IPCP: state change Ack-Sent --> Stopped Jan 30 11:20:25 ppp: [opt1] IPCP: LayerFinish Jan 30 11:20:25 ppp: [opt1] Bundle: No NCPs left. Closing links... Jan 30 11:20:25 ppp: [opt1] Bundle: closing link "opt1_link0"... Jan 30 11:20:25 ppp: [opt1_link0] Link: CLOSE event Jan 30 11:20:25 ppp: [opt1_link0] LCP: Close event Jan 30 11:20:25 ppp: [opt1_link0] LCP: state change Opened --> Closing Jan 30 11:20:25 ppp: [opt1_link0] Link: Leave bundle "opt1" Jan 30 11:20:25 ppp: [opt1] Bundle: Status update: up 0 links, total bandwidth 9600 bps Jan 30 11:20:25 ppp: [opt1] IPCP: Close event Jan 30 11:20:25 ppp: [opt1] IPCP: state change Stopped --> Closed Jan 30 11:20:25 ppp: [opt1] IPCP: Down event Jan 30 11:20:25 ppp: [opt1] IPCP: state change Closed --> Initial Jan 30 11:20:25 ppp: [opt1_link0] LCP: SendTerminateReq #3 Jan 30 11:20:25 ppp: [opt1_link0] LCP: LayerDown Jan 30 11:20:25 ppp: [opt1_link0] LCP: rec'd Terminate Ack #3 (Closing) Jan 30 11:20:25 ppp: [opt1_link0] LCP: state change Closing --> Closed Jan 30 11:20:25 ppp: [opt1_link0] LCP: LayerFinish Jan 30 11:20:25 ppp: [opt1_link0] Link: DOWN event Jan 30 11:20:25 ppp: [opt1_link0] LCP: Down event Jan 30 11:20:25 ppp: [opt1_link0] LCP: state change Closed --> Initial
-
This is what is happening when the huawei 3G connection is lost en never gets up again:
Looks like the USB connection of the huawei disconnects for a second and is connects again right after.
But the 3G connection never gets online again.
Do you see the same behavior?No, I don't see that device disconnection happen on my system. But I do see the "not converging" error message (despite successful authentication) when it tries to reconnect.
It seems to me that pfSense's PPP is too quick to give up permaently, and never try again.
OK, it's correct that pfSense should not try to endlessly reconnect every few seconds (this puts too much stress on the upstream ISP after a big outage). But pfSense should back off and try again every few minutes. That way the retry cycle is slow enough to avoid overloading the ISP network, for example if an upstream equipment failure kicks off all the users. But the present behaviour (just give up permanently if it doesn't seem to be working) seems wrong.
-
Have the same problem here with a HUAWEI E173 in Sweden with provider Tele2. Built up a similar configuration as martin42 and it worked very well in the beginning but the 3G connection failed more and more and the connection had to be reastablished manually. Now after about 2 month the connection doesn't even establish after "connect" in interfaces or after a reboot.
I think that it has something to do with the ICPC parameter negotiation which doesn't finish and it seems like that no valid IP-adress is given to the interface:
Mar 19 19:23:18 ppp: [opt1] IPCP: LayerFinish Mar 19 19:23:18 ppp: [opt1] IPCP: state change Req-Sent --> Stopped [glow]Mar 19 19:23:18 ppp: [opt1] IPCP: parameter negotiation failed Mar 19 19:23:18 ppp: [opt1] IPCP: not converging[/glow] Mar 19 19:23:18 ppp: [opt1] SECNBNS 10.11.12.14 Mar 19 19:23:18 ppp: [opt1] PRINBNS 10.11.12.13 Mar 19 19:23:18 ppp: [opt1] SECDNS 10.11.12.14 Mar 19 19:23:18 ppp: [opt1] PRIDNS 10.11.12.13 Mar 19 19:23:18 ppp: [opt1] IPCP: rec'd Configure Nak #10 (Req-Sent) Mar 19 19:23:17 ppp: [opt1] SECDNS 10.11.12.14 Mar 19 19:23:17 ppp: [opt1] PRIDNS 10.11.12.13 Mar 19 19:23:17 ppp: [opt1] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid [glow]Mar 19 19:23:17 ppp: [opt1] IPADDR 0.0.0.0[/glow]
I was also in contact with Tele2 and they said that there are no automatic disconnnects.
My next step is to build a test-environment so that I can track down the problem, I'll also try to connect with the same 3G-modem on a Win-machine. Do you have any new infos in this topic?
-
Hi,
changed to a Huawei E1750 modem and pfSense configurations unchanged and now it seems to work like a charm even when the modem gets an update of the IP-adress. The pfSense modem support list says something about that the E173 sometimes does not have a E173 chip inside, maybe that's the problem in this case.
Try changing to an different modem and the automatic reconnect may work.Maximilian