Hi Vick, I don't think I have much information for you but I have seen those similar logs before. I don't use mine as a backup but as a mobile router for events and only a couple of times a year. Usually in my experience it has been when there is not a strong signal that I see these problems. Because yours has worked just fine in the same place this may not be the cause.
-- Oliver Hansen On Thu, Apr 17, 2014 at 9:17 AM, Vick Khera <[email protected]> wrote: > At the advice of the group here, I installed a VZW UML290 usb modem > about a week and a half ago. This has worked pretty well as a backup > line since then. > > Starting yesterday, PPP won't negotiate anymore. The logs show the > authentication succeeds, but then the negotiation fails many times. > > Resetting and power-cycling the modem using usbconfig utility did not > help. (I am remote, so physically unplugging it is not possible right > now). > > I can type "AT" commands to the modem directly. > > Anyone else having negotiation troubles on verizon wireless data > modems? The account is in good standing according to their web portal. > > > Here are the logs produced (phone number redacted). The difference > between this and a successful connection is that the lines where it > reports refusal of VJCOMP. On successful attempt it looks like this: > > Apr 10 09:06:14 onceler ppp: [opt2] IPCP: state change Req-Sent --> > Ack-Sent > Apr 10 09:06:14 onceler ppp: [opt2] IPCP: rec'd Configure Reject #1 > (Ack-Sent) > Apr 10 09:06:14 onceler ppp: [opt2] COMPPROTO VJCOMP, 16 comp. > channels, no comp-cid > Apr 10 09:06:14 onceler ppp: [opt2] IPCP: SendConfigReq #2 > Apr 10 09:06:14 onceler ppp: [opt2] IPADDR 0.0.0.0 > Apr 10 09:06:14 onceler ppp: [opt2] IPCP: rec'd Configure Nak #2 (Ack-Sent) > Apr 10 09:06:14 onceler ppp: [opt2] IPADDR 10.185.224.29 > Apr 10 09:06:14 onceler ppp: [opt2] 10.185.224.29 is OK > Apr 10 09:06:14 onceler ppp: [opt2] IPCP: SendConfigReq #3 > Apr 10 09:06:14 onceler ppp: [opt2] IPADDR 10.185.224.29 > Apr 10 09:06:14 onceler ppp: [opt2] IPCP: rec'd Configure Ack #3 (Ack-Sent) > Apr 10 09:06:14 onceler ppp: [opt2] IPADDR 10.185.224.29 > Apr 10 09:06:14 onceler ppp: [opt2] IPCP: state change Ack-Sent --> Opened > Apr 10 09:06:14 onceler ppp: [opt2] IPCP: LayerUp > Apr 10 09:06:14 onceler ppp: [opt2] 10.185.224.29 -> 10.64.64.0 > Apr 10 09:06:14 onceler ppp: [opt2] IFACE: Up event > Apr 10 09:06:14 onceler ppp: [opt2] IFACE: Rename interface ng0 to ppp0 > > but unsuccessful attempt repeated the COMPPROTO VJCOMP several times > and gives up: > > Apr 17 11:53:38 onceler ppp: Multi-link PPP daemon for FreeBSD > Apr 17 11:53:38 onceler ppp: > Apr 17 11:53:38 onceler ppp: process 8572 started, version 5.6 > (root@snapshots-8_3-i386.builders.pfsense.org 10:16 24-Jul-2013) > Apr 17 11:53:38 onceler ppp: caught fatal signal term > Apr 17 11:53:38 onceler ppp: [opt2] IFACE: Close event > Apr 17 11:53:38 onceler ppp: [opt2] IPCP: Close event > Apr 17 11:53:38 onceler ppp: [opt2] IPV6CP: Close event > Apr 17 11:53:38 onceler ppp: waiting for process 53242 to die... > Apr 17 11:53:38 onceler php: /interfaces_ppps_edit.php: Starting > 3gstats.php on device '' for interface 'opt2' > Apr 17 11:53:39 onceler ppp: waiting for process 53242 to die... > Apr 17 11:53:40 onceler ppp: [opt2] Bundle: Shutdown > Apr 17 11:53:40 onceler ppp: [opt2_link0] Link: Shutdown > Apr 17 11:53:40 onceler ppp: process 53242 terminated > Apr 17 11:53:40 onceler ppp: web: web is not running > Apr 17 11:53:40 onceler ppp: [opt2] Bundle: Interface ng0 created > Apr 17 11:53:40 onceler ppp: [opt2_link0] Link: OPEN event > Apr 17 11:53:40 onceler kernel: ng0: changing name to 'ppp0' > Apr 17 11:53:40 onceler ppp: [opt2_link0] LCP: Open event > Apr 17 11:53:40 onceler ppp: [opt2_link0] LCP: state change Initial --> > Starting > Apr 17 11:53:40 onceler ppp: [opt2_link0] LCP: LayerStart > Apr 17 11:53:40 onceler ppp: [opt2_link0] CHAT: Detected Hayes compatible > modem. > Apr 17 11:53:40 onceler ppp: [opt2_link0] CHAT: Dialing server at > *99***3#... > Apr 17 11:53:40 onceler ppp: [opt2_link0] CHAT: ATDT*99***3# > Apr 17 11:53:40 onceler ppp: [opt2_link0] CHAT: Connected at 100000000. > Apr 17 11:53:40 onceler ppp: [opt2_link0] MODEM: chat script succeeded > Apr 17 11:53:40 onceler ppp: [opt2_link0] Link: UP event > Apr 17 11:53:40 onceler ppp: [opt2_link0] LCP: Up event > Apr 17 11:53:40 onceler ppp: [opt2_link0] LCP: state change Starting > --> Req-Sent > Apr 17 11:53:40 onceler ppp: [opt2_link0] LCP: SendConfigReq #1 > Apr 17 11:53:40 onceler ppp: [opt2_link0] ACFCOMP > Apr 17 11:53:40 onceler ppp: [opt2_link0] PROTOCOMP > Apr 17 11:53:40 onceler ppp: [opt2_link0] ACCMAP 0x000a0000 > Apr 17 11:53:40 onceler ppp: [opt2_link0] MRU 1500 > Apr 17 11:53:40 onceler ppp: [opt2_link0] MAGICNUM 7b339fe0 > Apr 17 11:53:40 onceler ppp: [opt2_link0] LCP: rec'd Configure Request > #25 (Req-Sent) > Apr 17 11:53:40 onceler ppp: [opt2_link0] ACCMAP 0x00000000 > Apr 17 11:53:40 onceler ppp: [opt2_link0] AUTHPROTO CHAP MD5 > Apr 17 11:53:40 onceler ppp: [opt2_link0] MAGICNUM e2e4d43f > Apr 17 11:53:40 onceler ppp: [opt2_link0] PROTOCOMP > Apr 17 11:53:40 onceler ppp: [opt2_link0] ACFCOMP > Apr 17 11:53:40 onceler ppp: [opt2_link0] LCP: SendConfigAck #25 > Apr 17 11:53:40 onceler ppp: [opt2_link0] ACCMAP 0x00000000 > Apr 17 11:53:40 onceler ppp: [opt2_link0] AUTHPROTO CHAP MD5 > Apr 17 11:53:40 onceler ppp: [opt2_link0] MAGICNUM e2e4d43f > Apr 17 11:53:40 onceler ppp: [opt2_link0] PROTOCOMP > Apr 17 11:53:40 onceler ppp: [opt2_link0] ACFCOMP > Apr 17 11:53:40 onceler ppp: [opt2_link0] LCP: state change Req-Sent > --> Ack-Sent > Apr 17 11:53:40 onceler ppp: [opt2_link0] LCP: rec'd Configure Ack #1 > (Ack-Sent) > Apr 17 11:53:40 onceler ppp: [opt2_link0] ACFCOMP > Apr 17 11:53:40 onceler ppp: [opt2_link0] PROTOCOMP > Apr 17 11:53:40 onceler ppp: [opt2_link0] ACCMAP 0x000a0000 > Apr 17 11:53:40 onceler ppp: [opt2_link0] MRU 1500 > Apr 17 11:53:40 onceler ppp: [opt2_link0] MAGICNUM 7b339fe0 > Apr 17 11:53:40 onceler ppp: [opt2_link0] LCP: state change Ack-Sent --> > Opened > Apr 17 11:53:40 onceler ppp: [opt2_link0] LCP: auth: peer wants CHAP, > I want nothing > Apr 17 11:53:40 onceler ppp: [opt2_link0] LCP: LayerUp > Apr 17 11:53:40 onceler ppp: [opt2_link0] LCP: rec'd Discard Request > #26 (Opened) > Apr 17 11:53:40 onceler ppp: [opt2_link0] CHAP: rec'd CHALLENGE #1 len: 35 > Apr 17 11:53:40 onceler ppp: [opt2_link0] Name: "UMTS_CHAP_SRVR" > Apr 17 11:53:40 onceler ppp: [opt2_link0] CHAP: Using authname > "[email protected]" > Apr 17 11:53:40 onceler ppp: [opt2_link0] CHAP: sending RESPONSE #1 len: 41 > Apr 17 11:53:40 onceler ppp: [opt2_link0] CHAP: rec'd SUCCESS #1 len: 4 > Apr 17 11:53:40 onceler ppp: [opt2_link0] LCP: authorization successful > Apr 17 11:53:40 onceler ppp: [opt2_link0] Link: Matched action 'bundle > "opt2" ""' > Apr 17 11:53:40 onceler ppp: [opt2_link0] Link: Join bundle "opt2" > Apr 17 11:53:40 onceler ppp: [opt2] Bundle: Status update: up 1 link, > total bandwidth 100000000 bps > Apr 17 11:53:40 onceler ppp: [opt2] IPCP: Open event > Apr 17 11:53:40 onceler ppp: [opt2] IPCP: state change Initial --> Starting > Apr 17 11:53:40 onceler ppp: [opt2] IPCP: LayerStart > Apr 17 11:53:40 onceler ppp: [opt2] IPV6CP: Open event > Apr 17 11:53:40 onceler ppp: [opt2] IPV6CP: state change Initial --> > Starting > Apr 17 11:53:40 onceler ppp: [opt2] IPV6CP: LayerStart > Apr 17 11:53:40 onceler ppp: [opt2] IPCP: Up event > Apr 17 11:53:40 onceler ppp: [opt2] IPCP: state change Starting --> > Req-Sent > Apr 17 11:53:40 onceler ppp: [opt2] IPCP: SendConfigReq #1 > Apr 17 11:53:40 onceler ppp: [opt2] IPADDR 0.0.0.0 > Apr 17 11:53:40 onceler ppp: [opt2] COMPPROTO VJCOMP, 16 comp. > channels, no comp-cid > Apr 17 11:53:40 onceler ppp: [opt2] IPV6CP: Up event > Apr 17 11:53:40 onceler ppp: [opt2] IPV6CP: state change Starting --> > Req-Sent > Apr 17 11:53:40 onceler ppp: [opt2] IPV6CP: SendConfigReq #1 > Apr 17 11:53:41 onceler ppp: [opt2] IPCP: rec'd Configure Nak #1 (Req-Sent) > Apr 17 11:53:41 onceler ppp: [opt2] IPCP: SendConfigReq #2 > Apr 17 11:53:41 onceler ppp: [opt2] IPADDR 0.0.0.0 > Apr 17 11:53:41 onceler ppp: [opt2] COMPPROTO VJCOMP, 16 comp. > channels, no comp-cid > Apr 17 11:53:42 onceler ppp: [opt2] IPV6CP: SendConfigReq #2 > Apr 17 11:53:42 onceler ppp: [opt2] IPCP: rec'd Configure Nak #2 (Req-Sent) > Apr 17 11:53:42 onceler ppp: [opt2] IPCP: SendConfigReq #3 > Apr 17 11:53:42 onceler ppp: [opt2] IPADDR 0.0.0.0 > Apr 17 11:53:42 onceler ppp: [opt2] COMPPROTO VJCOMP, 16 comp. > channels, no comp-cid > Apr 17 11:53:43 onceler ppp: [opt2] IPCP: rec'd Configure Nak #3 (Req-Sent) > Apr 17 11:53:43 onceler ppp: [opt2] IPCP: SendConfigReq #4 > Apr 17 11:53:43 onceler ppp: [opt2] IPADDR 0.0.0.0 > Apr 17 11:53:43 onceler ppp: [opt2] COMPPROTO VJCOMP, 16 comp. > channels, no comp-cid > Apr 17 11:53:44 onceler ppp: [opt2] IPV6CP: SendConfigReq #3 > Apr 17 11:53:44 onceler ppp: [opt2] IPCP: rec'd Configure Nak #4 (Req-Sent) > Apr 17 11:53:44 onceler ppp: [opt2] IPCP: SendConfigReq #5 > Apr 17 11:53:44 onceler ppp: [opt2] IPADDR 0.0.0.0 > Apr 17 11:53:44 onceler ppp: [opt2] COMPPROTO VJCOMP, 16 comp. > channels, no comp-cid > Apr 17 11:53:45 onceler ppp: [opt2] IPCP: rec'd Configure Nak #5 (Req-Sent) > Apr 17 11:53:45 onceler ppp: [opt2] IPCP: SendConfigReq #6 > Apr 17 11:53:45 onceler ppp: [opt2] IPADDR 0.0.0.0 > Apr 17 11:53:45 onceler ppp: [opt2] COMPPROTO VJCOMP, 16 comp. > channels, no comp-cid > Apr 17 11:53:46 onceler ppp: [opt2] IPV6CP: SendConfigReq #4 > Apr 17 11:53:46 onceler ppp: [opt2] IPCP: rec'd Configure Nak #6 (Req-Sent) > Apr 17 11:53:46 onceler ppp: [opt2] IPCP: SendConfigReq #7 > Apr 17 11:53:46 onceler ppp: [opt2] IPADDR 0.0.0.0 > Apr 17 11:53:46 onceler ppp: [opt2] COMPPROTO VJCOMP, 16 comp. > channels, no comp-cid > Apr 17 11:53:47 onceler ppp: [opt2] IPCP: rec'd Configure Nak #7 (Req-Sent) > Apr 17 11:53:47 onceler ppp: [opt2] IPCP: SendConfigReq #8 > Apr 17 11:53:47 onceler ppp: [opt2] IPADDR 0.0.0.0 > Apr 17 11:53:47 onceler ppp: [opt2] COMPPROTO VJCOMP, 16 comp. > channels, no comp-cid > Apr 17 11:53:48 onceler ppp: [opt2] IPV6CP: SendConfigReq #5 > Apr 17 11:53:48 onceler ppp: [opt2] IPCP: rec'd Configure Nak #8 (Req-Sent) > Apr 17 11:53:48 onceler ppp: [opt2] IPCP: SendConfigReq #9 > Apr 17 11:53:48 onceler ppp: [opt2] IPADDR 0.0.0.0 > Apr 17 11:53:48 onceler ppp: [opt2] COMPPROTO VJCOMP, 16 comp. > channels, no comp-cid > Apr 17 11:53:49 onceler ppp: [opt2] IPCP: rec'd Configure Nak #9 (Req-Sent) > Apr 17 11:53:49 onceler ppp: [opt2] IPCP: SendConfigReq #10 > Apr 17 11:53:49 onceler ppp: [opt2] IPADDR 0.0.0.0 > Apr 17 11:53:49 onceler ppp: [opt2] COMPPROTO VJCOMP, 16 comp. > channels, no comp-cid > Apr 17 11:53:50 onceler ppp: [opt2] IPV6CP: SendConfigReq #6 > Apr 17 11:53:50 onceler ppp: [opt2] IPCP: rec'd Configure Nak #10 > (Req-Sent) > Apr 17 11:53:50 onceler ppp: [opt2] IPCP: not converging > Apr 17 11:53:50 onceler ppp: [opt2] IPCP: parameter negotiation failed > Apr 17 11:53:50 onceler ppp: [opt2] IPCP: state change Req-Sent --> Stopped > Apr 17 11:53:50 onceler ppp: [opt2] IPCP: LayerFinish > Apr 17 11:53:52 onceler ppp: [opt2] IPV6CP: SendConfigReq #7 > Apr 17 11:53:54 onceler ppp: [opt2] IPV6CP: SendConfigReq #8 > Apr 17 11:53:56 onceler ppp: [opt2] IPV6CP: SendConfigReq #9 > Apr 17 11:53:58 onceler ppp: [opt2] IPV6CP: SendConfigReq #10 > Apr 17 11:54:00 onceler ppp: [opt2] IPV6CP: parameter negotiation failed > Apr 17 11:54:00 onceler ppp: [opt2] IPV6CP: state change Req-Sent --> > Stopped > Apr 17 11:54:00 onceler ppp: [opt2] IPV6CP: LayerFinish > Apr 17 11:54:00 onceler ppp: [opt2] Bundle: No NCPs left. Closing links... > Apr 17 11:54:00 onceler ppp: [opt2] Bundle: closing link "opt2_link0"... > Apr 17 11:54:00 onceler ppp: [opt2_link0] Link: CLOSE event > Apr 17 11:54:00 onceler ppp: [opt2_link0] LCP: Close event > Apr 17 11:54:00 onceler ppp: [opt2_link0] LCP: state change Opened --> > Closing > Apr 17 11:54:00 onceler ppp: [opt2_link0] Link: Leave bundle "opt2" > Apr 17 11:54:00 onceler ppp: [opt2] Bundle: Status update: up 0 links, > total bandwidth 9600 bps > Apr 17 11:54:00 onceler ppp: [opt2] IPCP: Close event > Apr 17 11:54:00 onceler ppp: [opt2] IPCP: state change Stopped --> Closed > Apr 17 11:54:00 onceler ppp: [opt2] IPV6CP: Close event > Apr 17 11:54:00 onceler ppp: [opt2] IPV6CP: state change Stopped --> Closed > Apr 17 11:54:00 onceler ppp: [opt2] IPCP: Down event > Apr 17 11:54:00 onceler ppp: [opt2] IPCP: state change Closed --> Initial > Apr 17 11:54:00 onceler ppp: [opt2] IPV6CP: Down event > Apr 17 11:54:00 onceler ppp: [opt2] IPV6CP: state change Closed --> Initial > Apr 17 11:54:00 onceler ppp: [opt2_link0] LCP: SendTerminateReq #2 > Apr 17 11:54:00 onceler ppp: [opt2_link0] LCP: LayerDown > Apr 17 11:54:00 onceler ppp: [opt2_link0] LCP: rec'd Terminate Ack #2 > (Closing) > Apr 17 11:54:00 onceler ppp: [opt2_link0] LCP: state change Closing --> > Closed > Apr 17 11:54:00 onceler ppp: [opt2_link0] LCP: LayerFinish > Apr 17 11:54:00 onceler ppp: [opt2_link0] Link: DOWN event > Apr 17 11:54:00 onceler ppp: [opt2_link0] LCP: Down event > Apr 17 11:54:00 onceler ppp: [opt2_link0] LCP: state change Closed --> > Initial > _______________________________________________ > List mailing list > [email protected] > https://lists.pfsense.org/mailman/listinfo/list >
_______________________________________________ List mailing list [email protected] https://lists.pfsense.org/mailman/listinfo/list
