Hi guys,
an update: I updated the device to pfSense 2.5.0 and had another drop in connection some days ago. These are the logs:
Apr 16 22:19:57 pvob ppp[7631]: [wan_link0] LCP: no reply to 1 echo request(s)
Apr 16 22:20:07 pvob ppp[7631]: [wan_link0] LCP: no reply to 2 echo request(s)
Apr 16 22:20:17 pvob ppp[7631]: [wan_link0] LCP: no reply to 3 echo request(s)
Apr 16 22:20:27 pvob ppp[7631]: [wan_link0] LCP: no reply to 4 echo request(s)
Apr 16 22:20:38 pvob ppp[7631]: [wan_link0] LCP: no reply to 5 echo request(s)
Apr 16 22:20:38 pvob ppp[7631]: [wan_link0] LCP: peer not responding to echo requests
Apr 16 22:20:38 pvob ppp[7631]: [wan_link0] LCP: state change Opened --> Stopping
Apr 16 22:20:38 pvob ppp[7631]: [wan_link0] Link: Leave bundle "wan"
Apr 16 22:20:38 pvob ppp[7631]: [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps
Apr 16 22:20:38 pvob ppp[7631]: [wan] IPCP: Close event
Apr 16 22:20:38 pvob ppp[7631]: [wan] IPCP: state change Opened --> Closing
Apr 16 22:20:38 pvob ppp[7631]: [wan] IPCP: SendTerminateReq #41
Apr 16 22:20:38 pvob ppp[7631]: [wan] IPCP: LayerDown
Apr 16 22:20:38 pvob ppp[7631]: [wan] IFACE: Down event
Apr 16 22:20:38 pvob ppp[7631]: [wan] IFACE: Rename interface ppp0 to ppp0
Apr 16 22:20:38 pvob ppp[7631]: [wan] IPV6CP: Close event
Apr 16 22:20:38 pvob ppp[7631]: [wan] IPV6CP: state change Stopped --> Closed
Apr 16 22:20:38 pvob ppp[7631]: [wan] IPCP: Down event
Apr 16 22:20:38 pvob ppp[7631]: [wan] IPCP: LayerFinish
Apr 16 22:20:38 pvob ppp[7631]: [wan] Bundle: No NCPs left. Closing links...
Apr 16 22:20:38 pvob ppp[7631]: [wan] IPCP: state change Closing --> Initial
Apr 16 22:20:38 pvob ppp[7631]: [wan] IPV6CP: Down event
Apr 16 22:20:38 pvob ppp[7631]: [wan] IPV6CP: state change Closed --> Initial
Apr 16 22:20:38 pvob ppp[7631]: [wan_link0] LCP: SendTerminateReq #21
Apr 16 22:20:38 pvob ppp[7631]: [wan_link0] LCP: LayerDown
Apr 16 22:20:40 pvob ppp[7631]: [wan_link0] LCP: SendTerminateReq #22
Apr 16 22:20:42 pvob ppp[7631]: [wan_link0] LCP: state change Stopping --> Stopped
Apr 16 22:20:42 pvob ppp[7631]: [wan_link0] LCP: LayerFinish
Apr 16 22:20:42 pvob ppp[7631]: [wan_link0] Link: DOWN event
Apr 16 22:20:42 pvob ppp[7631]: [wan_link0] LCP: Down event
Apr 16 22:20:42 pvob ppp[7631]: [wan_link0] LCP: state change Stopped --> Starting
Apr 16 22:20:42 pvob ppp[7631]: [wan_link0] LCP: LayerStart
Apr 16 22:20:42 pvob ppp[7631]: [wan_link0] LCP: state change Stopped --> Starting
Apr 16 22:20:42 pvob ppp[7631]: [wan_link0] LCP: LayerStart
Apr 16 22:20:42 pvob ppp[7631]: [wan_link0] Link: reconnection attempt 1 in 3 seconds
Apr 16 22:20:45 pvob ppp[7631]: [wan_link0] Link: reconnection attempt 1
Apr 16 22:20:45 pvob ppp[7631]: [wan_link0] CHAT: Detected Hayes compatible modem.
Apr 16 22:20:48 pvob ppp[7631]: [wan_link0] CHAT: The modem is not responding to "AT&F&C1&D2E0S0=0M1" at ModemCmd: label.
Apr 16 22:20:48 pvob ppp[7631]: [wan_link0] MODEM: chat script failed
Apr 16 22:20:48 pvob ppp[7631]: [wan_link0] Link: DOWN event
Apr 16 22:20:48 pvob ppp[7631]: [wan_link0] LCP: Down event
Apr 16 22:20:48 pvob ppp[7631]: [wan_link0] Link: reconnection attempt 2 in 2 seconds
Apr 16 22:20:50 pvob ppp[7631]: [wan_link0] Link: reconnection attempt 2
Apr 16 22:20:52 pvob ppp[7631]: [wan_link0] CHAT: The modem is not responding to "AT" at ModemCmd: label.
Apr 16 22:20:52 pvob ppp[7631]: [wan_link0] MODEM: chat script failed
Apr 16 22:20:52 pvob ppp[7631]: [wan_link0] Link: DOWN event
Apr 16 22:20:52 pvob ppp[7631]: [wan_link0] LCP: Down event
Apr 16 22:20:52 pvob ppp[7631]: [wan_link0] Link: reconnection attempt 3 in 2 seconds
Apr 16 22:20:54 pvob ppp[7631]: [wan_link0] Link: reconnection attempt 3
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] CHAT: +CGDCONT=1,"IP","Internet.t-d1.de"
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] CHAT: Detected Hayes compatible modem.
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] CHAT: Dialing server at *99#...
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] CHAT: ATDT*99#
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] CHAT: Connected at 100000000.
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] MODEM: chat script succeeded
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] Link: UP event
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] LCP: Up event
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] LCP: state change Starting --> Req-Sent
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] LCP: SendConfigReq #23
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] ACFCOMP
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] PROTOCOMP
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] ACCMAP 0x000a0000
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] MRU 1500
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] MAGICNUM 0xaff5169c
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] LCP: rec'd Configure Request #7 (Req-Sent)
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] ACCMAP 0x00000000
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] AUTHPROTO CHAP MD5
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] MAGICNUM 0x3d461fdb
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] PROTOCOMP
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] ACFCOMP
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] LCP: SendConfigAck #7
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] ACCMAP 0x00000000
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] AUTHPROTO CHAP MD5
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] MAGICNUM 0x3d461fdb
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] PROTOCOMP
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] ACFCOMP
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] LCP: state change Req-Sent --> Ack-Sent
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] LCP: rec'd Configure Ack #23 (Ack-Sent)
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] ACFCOMP
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] PROTOCOMP
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] ACCMAP 0x000a0000
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] MRU 1500
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] MAGICNUM 0xaff5169c
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] LCP: state change Ack-Sent --> Opened
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] LCP: auth: peer wants CHAP, I want nothing
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] LCP: LayerUp
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] LCP: rec'd Discard Request #8 (Opened)
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] CHAP: rec'd CHALLENGE #1 len: 35
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] Name: "UMTS_CHAP_SRVR"
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] CHAP: Using authname "t-mobile"
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] CHAP: sending RESPONSE #1 len: 29
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] CHAP: rec'd SUCCESS #1 len: 4
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] LCP: authorization successful
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] Link: Matched action 'bundle "wan" ""'
Apr 16 22:20:55 pvob ppp[7631]: [wan_link0] Link: Join bundle "wan"
Apr 16 22:20:55 pvob ppp[7631]: [wan] Bundle: Status update: up 1 link, total bandwidth 100000000 bps
Apr 16 22:20:55 pvob ppp[7631]: [wan] IPCP: Open event
Apr 16 22:20:55 pvob ppp[7631]: [wan] IPCP: state change Initial --> Starting
Apr 16 22:20:55 pvob ppp[7631]: [wan] IPCP: LayerStart
Apr 16 22:20:55 pvob ppp[7631]: [wan] IPV6CP: Open event
Apr 16 22:20:55 pvob ppp[7631]: [wan] IPV6CP: state change Initial --> Starting
Apr 16 22:20:55 pvob ppp[7631]: [wan] IPV6CP: LayerStart
Apr 16 22:20:55 pvob ppp[7631]: [wan] IPCP: Up event
Apr 16 22:20:55 pvob ppp[7631]: [wan] IPCP: state change Starting --> Req-Sent
Apr 16 22:20:55 pvob ppp[7631]: [wan] IPCP: SendConfigReq #42
Apr 16 22:20:55 pvob ppp[7631]: [wan] IPADDR 0.0.0.0
Apr 16 22:20:55 pvob ppp[7631]: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Apr 16 22:20:55 pvob ppp[7631]: [wan] IPV6CP: Up event
Apr 16 22:20:55 pvob ppp[7631]: [wan] IPV6CP: state change Starting --> Req-Sent
Apr 16 22:20:55 pvob ppp[7631]: [wan] IPV6CP: SendConfigReq #81
Apr 16 22:20:56 pvob ppp[7631]: [wan] IPCP: rec'd Configure Nak #42 (Req-Sent)
Apr 16 22:20:56 pvob ppp[7631]: [wan] IPCP: SendConfigReq #43
Apr 16 22:20:56 pvob ppp[7631]: [wan] IPADDR 0.0.0.0
Apr 16 22:20:56 pvob ppp[7631]: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Apr 16 22:20:57 pvob ppp[7631]: [wan] IPV6CP: SendConfigReq #82
Apr 16 22:20:57 pvob ppp[7631]: [wan] IPCP: rec'd Configure Nak #43 (Req-Sent)
Apr 16 22:20:57 pvob ppp[7631]: [wan] IPCP: SendConfigReq #44
Apr 16 22:20:57 pvob ppp[7631]: [wan] IPADDR 0.0.0.0
Apr 16 22:20:57 pvob ppp[7631]: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Apr 16 22:20:58 pvob ppp[7631]: [wan] IPCP: rec'd Configure Request #2 (Req-Sent)
Apr 16 22:20:58 pvob ppp[7631]: [wan] IPCP: SendConfigAck #2
Apr 16 22:20:58 pvob ppp[7631]: [wan] IPCP: state change Req-Sent --> Ack-Sent
Apr 16 22:20:58 pvob ppp[7631]: [wan] IPCP: rec'd Configure Reject #44 (Ack-Sent)
Apr 16 22:20:58 pvob ppp[7631]: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Apr 16 22:20:58 pvob ppp[7631]: [wan] IPCP: SendConfigReq #45
Apr 16 22:20:58 pvob ppp[7631]: [wan] IPADDR 0.0.0.0
Apr 16 22:20:58 pvob ppp[7631]: [wan] IPCP: rec'd Configure Nak #45 (Ack-Sent)
Apr 16 22:20:58 pvob ppp[7631]: [wan] IPADDR xxx.xxx.xxx.xxx
Apr 16 22:20:58 pvob ppp[7631]: [wan] xxx.xxx.xxx.xxx is OK
Apr 16 22:20:58 pvob ppp[7631]: [wan] IPCP: SendConfigReq #46
Apr 16 22:20:58 pvob ppp[7631]: [wan] IPADDR xxx.xxx.xxx.xxx
Apr 16 22:20:58 pvob ppp[7631]: [wan] IPCP: rec'd Configure Ack #46 (Ack-Sent)
Apr 16 22:20:58 pvob ppp[7631]: [wan] IPADDR xxx.xxx.xxx.xxx
Apr 16 22:20:58 pvob ppp[7631]: [wan] IPCP: state change Ack-Sent --> Opened
Apr 16 22:20:58 pvob ppp[7631]: [wan] IPCP: LayerUp
Apr 16 22:20:58 pvob ppp[7631]: [wan] xxx.xxx.xxx.xxx -> 10.64.64.0
Apr 16 22:20:58 pvob ppp[7631]: [wan] IFACE: Up event
Apr 16 22:20:58 pvob ppp[7631]: [wan] IFACE: Rename interface ng0 to ppp0
Apr 16 22:20:59 pvob ppp[7631]: [wan] IPV6CP: SendConfigReq #83
Apr 16 22:21:01 pvob ppp[7631]: [wan] IPV6CP: SendConfigReq #84
Apr 16 22:21:03 pvob ppp[7631]: [wan] IPV6CP: SendConfigReq #85
Apr 16 22:21:05 pvob ppp[7631]: [wan] IPV6CP: SendConfigReq #86
Apr 16 22:21:07 pvob ppp[7631]: [wan] IPV6CP: SendConfigReq #87
Apr 16 22:21:09 pvob ppp[7631]: [wan] IPV6CP: SendConfigReq #88
Apr 16 22:21:11 pvob ppp[7631]: [wan] IPV6CP: SendConfigReq #89
Apr 16 22:21:13 pvob ppp[7631]: [wan] IPV6CP: SendConfigReq #90
Apr 16 22:21:15 pvob ppp[7631]: [wan] IPV6CP: parameter negotiation failed
Apr 16 22:21:15 pvob ppp[7631]: [wan] IPV6CP: state change Req-Sent --> Stopped
Apr 16 22:21:15 pvob ppp[7631]: [wan] IPV6CP: LayerFinish
This time, I initiated a WAN reconnect through the web interface and got the following PPP log:
Apr 17 11:03:07 pvob ppp[7631]: caught fatal signal TERM
Apr 17 11:03:07 pvob ppp[7631]: [wan] IFACE: Close event
Apr 17 11:03:07 pvob ppp[7631]: [wan] IPCP: Close event
Apr 17 11:03:07 pvob ppp[7631]: [wan] IPCP: state change Opened --> Closing
Apr 17 11:03:07 pvob ppp[7631]: [wan] IPCP: SendTerminateReq #47
Apr 17 11:03:07 pvob ppp[7631]: [wan] IPCP: LayerDown
Apr 17 11:03:07 pvob ppp[7631]: [wan] IFACE: Down event
Apr 17 11:03:07 pvob ppp[7631]: [wan] IFACE: Rename interface ppp0 to ppp0
Apr 17 11:03:07 pvob ppp[7631]: [wan] IPV6CP: Close event
Apr 17 11:03:07 pvob ppp[7631]: [wan] IPV6CP: state change Stopped --> Closed
Apr 17 11:03:07 pvob ppp[7631]: [wan] IPCP: rec'd Terminate Ack #47 (Closing)
Apr 17 11:03:07 pvob ppp[7631]: [wan] IPCP: state change Closing --> Closed
Apr 17 11:03:07 pvob ppp[7631]: [wan] IPCP: LayerFinish
Apr 17 11:03:07 pvob ppp[7631]: [wan] Bundle: No NCPs left. Closing links...
Apr 17 11:03:07 pvob ppp[7631]: [wan] Bundle: closing link "wan_link0"...
Apr 17 11:03:07 pvob ppp[7631]: [wan_link0] Link: CLOSE event
Apr 17 11:03:07 pvob ppp[7631]: [wan_link0] LCP: Close event
Apr 17 11:03:07 pvob ppp[7631]: [wan_link0] LCP: state change Opened --> Closing
Apr 17 11:03:07 pvob ppp[7631]: [wan_link0] Link: Leave bundle "wan"
Apr 17 11:03:07 pvob ppp[7631]: [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps
Apr 17 11:03:07 pvob ppp[7631]: [wan] IPCP: Close event
Apr 17 11:03:07 pvob ppp[7631]: [wan] IPV6CP: Close event
Apr 17 11:03:07 pvob ppp[7631]: [wan] IPCP: Down event
Apr 17 11:03:07 pvob ppp[7631]: [wan] IPCP: state change Closed --> Initial
Apr 17 11:03:07 pvob ppp[7631]: [wan] IPV6CP: Down event
Apr 17 11:03:07 pvob ppp[7631]: [wan] IPV6CP: state change Closed --> Initial
Apr 17 11:03:07 pvob ppp[7631]: [wan_link0] LCP: SendTerminateReq #24
Apr 17 11:03:07 pvob ppp[7631]: [wan_link0] LCP: LayerDown
Apr 17 11:03:07 pvob ppp[7631]: [wan_link0] LCP: rec'd Terminate Ack #24 (Closing)
Apr 17 11:03:07 pvob ppp[7631]: [wan_link0] LCP: state change Closing --> Closed
Apr 17 11:03:07 pvob ppp[7631]: [wan_link0] LCP: LayerFinish
Apr 17 11:03:07 pvob ppp[7631]: [wan_link0] Link: DOWN event
Apr 17 11:03:07 pvob ppp[7631]: [wan_link0] LCP: Down event
Apr 17 11:03:07 pvob ppp[7631]: [wan_link0] LCP: state change Closed --> Initial
Apr 17 11:03:09 pvob ppp[7631]: [wan] Bundle: Shutdown
Apr 17 11:03:09 pvob ppp[7631]: [wan_link0] Link: Shutdown
Apr 17 11:03:09 pvob ppp[7631]: process 7631 terminated
Apr 17 11:03:14 pvob ppp[39865]: Multi-link PPP daemon for FreeBSD
Apr 17 11:03:14 pvob ppp[39865]:
Apr 17 11:03:14 pvob ppp[39865]: process 39865 started, version 5.9
Apr 17 11:03:14 pvob ppp[39865]: web: web is not running
Apr 17 11:03:14 pvob ppp[39865]: [wan] Bundle: Interface ng0 created
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] Link: OPEN event
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] LCP: Open event
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] LCP: state change Initial --> Starting
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] LCP: LayerStart
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] CHAT: +CGDCONT=1,"IP","Internet.t-d1.de"
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] CHAT: Detected Hayes compatible modem.
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] CHAT: Dialing server at *99#...
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] CHAT: ATDT*99#
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] CHAT: Connected at 100000000.
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] MODEM: chat script succeeded
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] Link: UP event
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] LCP: Up event
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] LCP: state change Starting --> Req-Sent
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] LCP: SendConfigReq #1
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] ACFCOMP
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] PROTOCOMP
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] ACCMAP 0x000a0000
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] MRU 1500
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] MAGICNUM 0xd2d06e1f
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] LCP: rec'd Configure Request #9 (Req-Sent)
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] ACCMAP 0x00000000
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] AUTHPROTO CHAP MD5
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] MAGICNUM 0x40000b17
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] AUTHPROTO CHAP MD5
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] MAGICNUM 0x40000b17
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] PROTOCOMP
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] ACFCOMP
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] LCP: SendConfigAck #9
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] ACCMAP 0x00000000
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] AUTHPROTO CHAP MD5
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] MAGICNUM 0x40000b17
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] PROTOCOMP
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] ACFCOMP
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] LCP: state change Req-Sent --> Ack-Sent
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] LCP: rec'd Configure Ack #1 (Ack-Sent)
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] ACFCOMP
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] PROTOCOMP
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] ACCMAP 0x000a0000
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] MRU 1500
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] MAGICNUM 0xd2d06e1f
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] LCP: state change Ack-Sent --> Opened
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] LCP: auth: peer wants CHAP, I want nothing
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] LCP: LayerUp
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] LCP: rec'd Discard Request #10 (Opened)
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] CHAP: rec'd CHALLENGE #1 len: 35
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] Name: "UMTS_CHAP_SRVR"
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] CHAP: Using authname "t-mobile"
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] CHAP: sending RESPONSE #1 len: 29
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] CHAP: rec'd SUCCESS #1 len: 4
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] LCP: authorization successful
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] Link: Matched action 'bundle "wan" ""'
Apr 17 11:03:14 pvob ppp[39865]: [wan_link0] Link: Join bundle "wan"
Apr 17 11:03:14 pvob ppp[39865]: [wan] Bundle: Status update: up 1 link, total bandwidth 100000000 bps
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPCP: Open event
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPCP: state change Initial --> Starting
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPCP: LayerStart
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPV6CP: Open event
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPV6CP: state change Initial --> Starting
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPV6CP: LayerStart
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPCP: Up event
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPCP: state change Starting --> Req-Sent
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPCP: SendConfigReq #1
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPADDR 0.0.0.0
Apr 17 11:03:14 pvob ppp[39865]: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPV6CP: Up event
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPV6CP: state change Starting --> Req-Sent
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPV6CP: SendConfigReq #1
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPCP: rec'd Configure Request #3 (Req-Sent)
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPCP: SendConfigAck #3
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPCP: state change Req-Sent --> Ack-Sent
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPCP: rec'd Configure Reject #1 (Ack-Sent)
Apr 17 11:03:14 pvob ppp[39865]: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPCP: SendConfigReq #2
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPADDR 0.0.0.0
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPCP: rec'd Configure Nak #2 (Ack-Sent)
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPADDR xxx.xxx.xxx.xxx
Apr 17 11:03:14 pvob ppp[39865]: [wan] xxx.xxx.xxx.xxx is OK
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPCP: SendConfigReq #3
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPADDR xxx.xxx.xxx.xxx
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPCP: rec'd Configure Ack #3 (Ack-Sent)
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPADDR xxx.xxx.xxx.xxx
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPCP: state change Ack-Sent --> Opened
Apr 17 11:03:14 pvob ppp[39865]: [wan] IPCP: LayerUp
Apr 17 11:03:14 pvob ppp[39865]: [wan] xxx.xxx.xxx.xxx -> 10.64.64.0
Apr 17 11:03:14 pvob ppp[39865]: [wan] IFACE: Up event
Apr 17 11:03:14 pvob ppp[39865]: [wan] IFACE: Rename interface ng0 to ppp0
Apr 17 11:03:16 pvob ppp[39865]: [wan] IPV6CP: SendConfigReq #2
Apr 17 11:03:18 pvob ppp[39865]: [wan] IPV6CP: SendConfigReq #3
Apr 17 11:03:20 pvob ppp[39865]: [wan] IPV6CP: SendConfigReq #4
Apr 17 11:03:22 pvob ppp[39865]: [wan] IPV6CP: SendConfigReq #5
Apr 17 11:03:24 pvob ppp[39865]: [wan] IPV6CP: SendConfigReq #6
Apr 17 11:03:26 pvob ppp[39865]: [wan] IPV6CP: SendConfigReq #7
Apr 17 11:03:28 pvob ppp[39865]: [wan] IPV6CP: SendConfigReq #8
Apr 17 11:03:30 pvob ppp[39865]: [wan] IPV6CP: SendConfigReq #9
Apr 17 11:03:32 pvob ppp[39865]: [wan] IPV6CP: SendConfigReq #10
Apr 17 11:03:34 pvob ppp[39865]: [wan] IPV6CP: parameter negotiation failed
Apr 17 11:03:34 pvob ppp[39865]: [wan] IPV6CP: state change Req-Sent --> Stopped
Apr 17 11:03:34 pvob ppp[39865]: [wan] IPV6CP: LayerFinish
Apr 17 11:15:38 pvob ppp[39865]: caught fatal signal TERM
Apr 17 11:15:38 pvob ppp[39865]: [wan] IFACE: Close event
Apr 17 11:15:38 pvob ppp[39865]: [wan] IPCP: Close event
Apr 17 11:15:38 pvob ppp[39865]: [wan] IPCP: state change Opened --> Closing
Apr 17 11:15:38 pvob ppp[39865]: [wan] IPCP: SendTerminateReq #4
Apr 17 11:15:38 pvob ppp[39865]: [wan] IPCP: LayerDown
Apr 17 11:18:03 pvob ppp[10783]: Multi-link PPP daemon for FreeBSD
Apr 17 11:18:03 pvob ppp[10783]:
Apr 17 11:18:03 pvob ppp[10783]: process 10783 started, version 5.9
Apr 17 11:18:03 pvob ppp[10783]: web: web is not running
Apr 17 11:18:03 pvob ppp[10783]: [wan] Bundle: Interface ng0 created
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] Link: OPEN event
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] LCP: Open event
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] LCP: state change Initial --> Starting
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] LCP: LayerStart
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] CHAT: +CGDCONT=1,"IP","Internet.t-d1.de"
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] CHAT: Detected Hayes compatible modem.
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] CHAT: +CGDCONT=1,"IP","Internet.t-d1.de"
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] CHAT: Detected Hayes compatible modem.
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] CHAT: Dialing server at *99#...
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] CHAT: ATDT*99#
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] CHAT: Connected at 100000000.
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] MODEM: chat script succeeded
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] Link: UP event
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] LCP: Up event
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] LCP: state change Starting --> Req-Sent
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] LCP: SendConfigReq #1
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] ACFCOMP
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] PROTOCOMP
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] ACCMAP 0x000a0000
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] MRU 1500
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] MAGICNUM 0x57c42c5c
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] LCP: rec'd Configure Request #11 (Req-Sent)
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] ACCMAP 0x00000000
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] AUTHPROTO CHAP MD5
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] MAGICNUM 0x400d999a
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] PROTOCOMP
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] ACFCOMP
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] LCP: SendConfigAck #11
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] ACCMAP 0x00000000
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] AUTHPROTO CHAP MD5
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] MAGICNUM 0x400d999a
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] PROTOCOMP
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] ACFCOMP
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] LCP: state change Req-Sent --> Ack-Sent
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] LCP: rec'd Configure Ack #1 (Ack-Sent)
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] ACFCOMP
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] PROTOCOMP
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] ACCMAP 0x000a0000
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] MRU 1500
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] MAGICNUM 0x57c42c5c
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] LCP: state change Ack-Sent --> Opened
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] LCP: auth: peer wants CHAP, I want nothing
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] LCP: LayerUp
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] LCP: rec'd Discard Request #12 (Opened)
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] CHAP: rec'd CHALLENGE #1 len: 35
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] Name: "UMTS_CHAP_SRVR"
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] CHAP: Using authname "t-mobile"
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] CHAP: sending RESPONSE #1 len: 29
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] CHAP: rec'd SUCCESS #1 len: 4
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] LCP: authorization successful
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] Link: Matched action 'bundle "wan" ""'
Apr 17 11:18:03 pvob ppp[10783]: [wan_link0] Link: Join bundle "wan"
Apr 17 11:18:03 pvob ppp[10783]: [wan] Bundle: Status update: up 1 link, total bandwidth 100000000 bps
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPCP: Open event
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPCP: state change Initial --> Starting
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPCP: LayerStart
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPV6CP: Open event
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPV6CP: state change Initial --> Starting
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPV6CP: LayerStart
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPCP: Up event
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPCP: state change Starting --> Req-Sent
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPCP: SendConfigReq #1
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPADDR 0.0.0.0
Apr 17 11:18:03 pvob ppp[10783]: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPV6CP: Up event
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPV6CP: state change Starting --> Req-Sent
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPV6CP: SendConfigReq #1
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPCP: rec'd Configure Request #4 (Req-Sent)
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPCP: SendConfigAck #4
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPCP: state change Req-Sent --> Ack-Sent
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPCP: rec'd Configure Reject #1 (Ack-Sent)
Apr 17 11:18:03 pvob ppp[10783]: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPCP: SendConfigReq #2
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPADDR 0.0.0.0
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPCP: rec'd Configure Nak #2 (Ack-Sent)
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPADDR xxx.xxx.xxx.xxx
Apr 17 11:18:03 pvob ppp[10783]: [wan] xxx.xxx.xxx.xxx is OK
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPCP: SendConfigReq #3
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPADDR xxx.xxx.xxx.xxx
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPCP: rec'd Configure Ack #3 (Ack-Sent)
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPADDR xxx.xxx.xxx.xxx
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPCP: state change Ack-Sent --> Opened
Apr 17 11:18:03 pvob ppp[10783]: [wan] IPCP: LayerUp
Apr 17 11:18:03 pvob ppp[10783]: [wan] xxx.xxx.xxx.xxx -> 10.64.64.0
Apr 17 11:18:03 pvob ppp[10783]: [wan] IFACE: Up event
Apr 17 11:18:03 pvob ppp[10783]: [wan] IFACE: Rename interface ng0 to ppp0
Apr 17 11:18:05 pvob ppp[10783]: [wan] IPV6CP: SendConfigReq #2
Apr 17 11:18:07 pvob ppp[10783]: [wan] IPV6CP: SendConfigReq #3
Apr 17 11:18:09 pvob ppp[10783]: [wan] IPV6CP: SendConfigReq #4
Apr 17 11:18:11 pvob ppp[10783]: [wan] IPV6CP: SendConfigReq #5
Apr 17 11:18:13 pvob ppp[10783]: [wan] IPV6CP: SendConfigReq #6
Apr 17 11:18:15 pvob ppp[10783]: [wan] IPV6CP: SendConfigReq #7
Apr 17 11:18:17 pvob ppp[10783]: [wan] IPV6CP: SendConfigReq #8
Apr 17 11:18:19 pvob ppp[10783]: [wan] IPV6CP: SendConfigReq #9
Apr 17 11:18:21 pvob ppp[10783]: [wan] IPV6CP: SendConfigReq #10
Apr 17 11:18:23 pvob ppp[10783]: [wan] IPV6CP: parameter negotiation failed
Apr 17 11:18:23 pvob ppp[10783]: [wan] IPV6CP: state change Req-Sent --> Stopped
Apr 17 11:18:23 pvob ppp[10783]: [wan] IPV6CP: LayerFinish
I was not able to spot any relevant difference between the successful and unsuccessful attempt, even the assigned IP is the same. To me it seems that the issue seems to be located somewhere else than in WAN connectivity.
I'll investigate further...