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 down

    If 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


  • @martin42:

    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>
    

  • Rebel Alliance Developer Netgate

    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?



  • @jimp:

    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
    


  • @GrandmasterB:

    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


Log in to reply