Some 3g related problems with E153 modem and Virgin Mobile in Australia

wallabybob

I have just upgraded to 2.1-DEVELOPMENT (i386)
built on Tue Apr 17 16:58:04 EDT 2012
FreeBSD 8.3-RELEASE

On this box I used to have a 3G mobile broadband link to Optus using a Huawei E1762 USB 3G modem. After the upgrade I tried to use a Huawei E153 USB 3G modem to connect to Virgin Mobile. I had the same modem (E153) connect to Virgin Mobile on a small TP-Link box running OpenWRT. The E153 is recognised by the u3g driver in pfSense.

On the appropriate interface page, under PPP configuration I selected Country, Provider and Plan and clicked Save but these details (Country, Provider and Plan) were not remembered. Should they have been remembered?

I have seen reports that Virgin Mobile needs to have PAP (and only PAP) authentication enabled so I clicked on the Click here to edit PPP configuration beside Advanced PPP on the Interface page and six minutes later the browser was still displaying the page with the Click here link and reporting it was waiting for the pfSense box. I aborted the page load and clicked the browser Refresh button to reload the Interface page but more than 5 minutes later the browser was still reporting it was waiting for the pfSense box. My SSH session to the pfSense box was still working and top reported 98% idle time.

The PPP log contained

Apr 18 22:33:24 pfsense2 ppp: caught fatal signal term
Apr 18 22:33:24 pfsense2 ppp: [opt3] IPCP: Close event
Apr 18 22:33:15 pfsense2 ppp: [opt3] IPCP: SendConfigReq #4
Apr 18 22:33:15 pfsense2 ppp: [opt3] IPADDR 0.0.0.0
Apr 18 22:33:15 pfsense2 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Apr 18 22:33:15 pfsense2 ppp: [opt3] PRIDNS 0.0.0.0
Apr 18 22:33:15 pfsense2 ppp: [opt3] SECDNS 0.0.0.0
Apr 18 22:33:15 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #4
Apr 18 22:33:17 pfsense2 ppp: [opt3] IPCP: SendConfigReq #5
Apr 18 22:33:17 pfsense2 ppp: [opt3] IPADDR 0.0.0.0
Apr 18 22:33:17 pfsense2 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Apr 18 22:33:17 pfsense2 ppp: [opt3] PRIDNS 0.0.0.0
Apr 18 22:33:17 pfsense2 ppp: [opt3] SECDNS 0.0.0.0
Apr 18 22:33:17 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #5
Apr 18 22:33:19 pfsense2 ppp: [opt3] IPCP: SendConfigReq #6
Apr 18 22:33:19 pfsense2 ppp: [opt3] IPADDR 0.0.0.0
Apr 18 22:33:19 pfsense2 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Apr 18 22:33:19 pfsense2 ppp: [opt3] PRIDNS 0.0.0.0
Apr 18 22:33:19 pfsense2 ppp: [opt3] SECDNS 0.0.0.0
Apr 18 22:33:19 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #6
Apr 18 22:33:21 pfsense2 ppp: [opt3] IPCP: SendConfigReq #7
Apr 18 22:33:21 pfsense2 ppp: [opt3] IPADDR 0.0.0.0
Apr 18 22:33:21 pfsense2 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Apr 18 22:33:21 pfsense2 ppp: [opt3] PRIDNS 0.0.0.0
Apr 18 22:33:21 pfsense2 ppp: [opt3] SECDNS 0.0.0.0
Apr 18 22:33:21 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #7
Apr 18 22:33:23 pfsense2 ppp: [opt3] IPCP: SendConfigReq #8
Apr 18 22:33:23 pfsense2 ppp: [opt3] IPADDR 0.0.0.0
Apr 18 22:33:23 pfsense2 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Apr 18 22:33:23 pfsense2 ppp: [opt3] PRIDNS 0.0.0.0
Apr 18 22:33:23 pfsense2 ppp: [opt3] SECDNS 0.0.0.0
Apr 18 22:33:23 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #8
Apr 18 22:33:25 pfsense2 ppp: [opt3] IPCP: SendConfigReq #9
Apr 18 22:33:25 pfsense2 ppp: [opt3] IPADDR 0.0.0.0
Apr 18 22:33:25 pfsense2 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Apr 18 22:33:25 pfsense2 ppp: [opt3] PRIDNS 0.0.0.0
Apr 18 22:33:25 pfsense2 ppp: [opt3] SECDNS 0.0.0.0
Apr 18 22:33:25 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #9
Apr 18 22:35:11 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #10
Apr 18 22:35:11 pfsense2 ppp: [opt3] IPCP: SendConfigReq #10
Apr 18 22:35:11 pfsense2 ppp: [opt3] IPADDR 0.0.0.0
Apr 18 22:35:11 pfsense2 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Apr 18 22:35:11 pfsense2 ppp: [opt3] PRIDNS 0.0.0.0
Apr 18 22:35:11 pfsense2 ppp: [opt3] SECDNS 0.0.0.0
Apr 18 22:35:11 pfsense2 ppp: [opt3_link0] LCP: no reply to 1 echo request(s)
Apr 18 22:35:13 pfsense2 ppp: [opt3] IPV6CP: parameter negotiation failed
Apr 18 22:35:13 pfsense2 ppp: [opt3] IPV6CP: state change Req-Sent –> Stopped
Apr 18 22:35:13 pfsense2 ppp: [opt3] IPV6CP: LayerFinish
Apr 18 22:35:13 pfsense2 ppp: [opt3] IPCP: parameter negotiation failed
Apr 18 22:35:13 pfsense2 ppp: [opt3] IPCP: state change Req-Sent –> Stopped
Apr 18 22:35:13 pfsense2 ppp: [opt3] IPCP: LayerFinish
Apr 18 22:35:13 pfsense2 ppp: [opt3] Bundle: No NCPs left. Closing links…
Apr 18 22:35:13 pfsense2 ppp: [opt3] Bundle: closing link "opt3_link0"…
Apr 18 22:35:13 pfsense2 ppp: [opt3_link0] Link: CLOSE event
Apr 18 22:35:13 pfsense2 ppp: [opt3_link0] LCP: Close event
Apr 18 22:35:13 pfsense2 ppp: [opt3_link0] LCP: state change Opened –> Closing
Apr 18 22:35:13 pfsense2 ppp: [opt3_link0] Link: Leave bundle "opt3"
Apr 18 22:35:13 pfsense2 ppp: [opt3] Bundle: Status update: up 0 links, total bandwidth 9600 bps
Apr 18 22:35:13 pfsense2 ppp: [opt3] IPCP: Close event
Apr 18 22:35:13 pfsense2 ppp: [opt3] IPCP: state change Stopped –> Closed
Apr 18 22:35:13 pfsense2 ppp: [opt3] IPV6CP: Close event
Apr 18 22:35:13 pfsense2 ppp: [opt3] IPV6CP: state change Stopped –> Closed
Apr 18 22:35:13 pfsense2 ppp: [opt3] IPCP: Down event
Apr 18 22:35:13 pfsense2 ppp: [opt3] IPCP: state change Closed –> Initial
Apr 18 22:35:13 pfsense2 ppp: [opt3] IPV6CP: Down event
Apr 18 22:35:13 pfsense2 ppp: [opt3] IPV6CP: state change Closed –> Initial
Apr 18 22:35:13 pfsense2 ppp: [opt3_link0] LCP: SendTerminateReq #2
Apr 18 22:35:13 pfsense2 ppp: [opt3_link0] LCP: LayerDown
Apr 18 22:35:15 pfsense2 ppp: [opt3_link0] LCP: SendTerminateReq #3
Apr 18 22:35:17 pfsense2 ppp: [opt3_link0] LCP: state change Closing –> Closed
Apr 18 22:35:17 pfsense2 ppp: [opt3_link0] LCP: LayerFinish
Apr 18 22:35:17 pfsense2 ppp: [opt3_link0] Link: DOWN event
Apr 18 22:35:17 pfsense2 ppp: [opt3_link0] LCP: Down event
Apr 18 22:35:17 pfsense2 ppp: [opt3_link0] LCP: state change Closed –> Initial
$

I restarted the pfSense web configurator from the SSH menu but the browser wouldn't load the pfSense home page, reporting Connecting …

Hi -

Apr 18 22:35:11 pfsense2 ppp: [opt3_link0] LCP: no reply to 1 echo request(s)

I had a similar output when first trying cuaU0.1 with my 4g.
In this case it was a diag or control port and not suitable for the link even if it accepts commands.
Maybe, if it has a second port like cuaU0.2 it will work better.
Sometimes, the modem may need more/different initialisation too- mine for example doesnt accept init commands when the pin isnt sent.

I also noticed that my country settings got lost but this was at least not serious for the functionality. (normally this is used for countrycodes when dialing or the network technology to set in different countries)

wallabybob

@ThorstenK:

Hi - i had a similar output when first trying cuaU0.1 with my 4g.
In this case it was a diag or control port and not suitable for the link even if it accepts commands.
Maybe, if it has a second port like cuaU0.2 it works better.

The modem works fine using ttyUSB0 on Ubuntu 11.10 and 12.04 and on DD-Wrt. But I can try using another port on pfSense.

@ThorstenK:

Sometimes, the modem may need more/different initialisation too- mine for example doesnt accept init commands when the pin isnt sent.

Very basic setup commands were sufficient in DD-Wrt. But it seemed I had to do a number of tweaks to the PPP configuration file to get PPP to negotiate correctly (exclude all authentications except PAP). It is pretty easy to setup Ubuntu to restrict the authentication options.

wallabybob

Solved by some tweaks to the PPP configuration.

I haven't yet figured out how to get the web GUI to allow selection of network specific PPP options.

Here's an extract of the pfSense PPP log when it would start PPP to Virgin Mobile:```

May 16 11:57:48 pfsense2 ppp: Multi-link PPP daemon for FreeBSD
May 16 11:57:48 pfsense2 ppp:
May 16 11:57:48 pfsense2 ppp: process 51484 started, version 5.6 (root@FreeBSD_8.3_pfSense_2.1.snaps.pfsense.org 13:36 1-May-2012)
May 16 11:57:48 pfsense2 ppp: web: web is not running
May 16 11:57:48 pfsense2 ppp: [opt3] Bundle: Interface ng0 created
May 16 11:57:48 pfsense2 ppp: [opt3_link0] Link: OPEN event
May 16 11:57:48 pfsense2 ppp: [opt3_link0] LCP: Open event
May 16 11:57:48 pfsense2 ppp: [opt3_link0] LCP: state change Initial --> Starting
May 16 11:57:48 pfsense2 ppp: [opt3_link0] LCP: LayerStart
May 16 11:57:48 pfsense2 ppp: [opt3_link0] CHAT: Detected Hayes compatible modem.
May 16 11:57:48 pfsense2 ppp: [opt3_link0] CHAT: Sending Custom init
May 16 11:57:48 pfsense2 ppp: [opt3_link0] CHAT: OK
May 16 11:57:48 pfsense2 ppp: [opt3_link0] CHAT: Dialing server at *99#...
May 16 11:57:48 pfsense2 ppp: [opt3_link0] CHAT: Connected at an unknown speed.
May 16 11:57:48 pfsense2 ppp: [opt3_link0] MODEM: chat script succeeded
May 16 11:57:48 pfsense2 ppp: [opt3_link0] Link: UP event
May 16 11:57:48 pfsense2 ppp: [opt3_link0] LCP: Up event
May 16 11:57:48 pfsense2 ppp: [opt3_link0] LCP: state change Starting --> Req-Sent
May 16 11:57:48 pfsense2 ppp: [opt3_link0] LCP: SendConfigReq #1
May 16 11:57:48 pfsense2 ppp: [opt3_link0] ACFCOMP
May 16 11:57:48 pfsense2 ppp: [opt3_link0] PROTOCOMP
May 16 11:57:48 pfsense2 ppp: [opt3_link0] ACCMAP 0x000a0000
May 16 11:57:48 pfsense2 ppp: [opt3_link0] MRU 1500
May 16 11:57:48 pfsense2 ppp: [opt3_link0] MAGICNUM 83ed3650
May 16 11:57:48 pfsense2 ppp: [opt3_link0] LCP: rec'd Configure Request #2 (Req-Sent)
May 16 11:57:48 pfsense2 ppp: [opt3_link0] ACCMAP 0x00000000
May 16 11:57:48 pfsense2 ppp: [opt3_link0] AUTHPROTO CHAP MD5
May 16 11:57:48 pfsense2 ppp: [opt3_link0] MAGICNUM 0107e805
May 16 11:57:48 pfsense2 ppp: [opt3_link0] PROTOCOMP
May 16 11:57:48 pfsense2 ppp: [opt3_link0] ACFCOMP
May 16 11:57:48 pfsense2 ppp: [opt3_link0] LCP: SendConfigAck #2
May 16 11:57:48 pfsense2 ppp: [opt3_link0] ACCMAP 0x00000000
May 16 11:57:48 pfsense2 ppp: [opt3_link0] AUTHPROTO CHAP MD5
May 16 11:57:48 pfsense2 ppp: [opt3_link0] MAGICNUM 0107e805
May 16 11:57:48 pfsense2 ppp: [opt3_link0] PROTOCOMP
May 16 11:57:48 pfsense2 ppp: [opt3_link0] ACFCOMP
May 16 11:57:48 pfsense2 ppp: [opt3_link0] LCP: state change Req-Sent --> Ack-Sent
May 16 11:57:48 pfsense2 ppp: [opt3_link0] LCP: rec'd Configure Ack #1 (Ack-Sent)
May 16 11:57:48 pfsense2 ppp: [opt3_link0] ACFCOMP
May 16 11:57:48 pfsense2 ppp: [opt3_link0] PROTOCOMP
May 16 11:57:48 pfsense2 ppp: [opt3_link0] ACCMAP 0x000a0000
May 16 11:57:48 pfsense2 ppp: [opt3_link0] MRU 1500
May 16 11:57:48 pfsense2 ppp: [opt3_link0] MAGICNUM 83ed3650
May 16 11:57:48 pfsense2 ppp: [opt3_link0] LCP: state change Ack-Sent --> Opened
May 16 11:57:48 pfsense2 ppp: [opt3_link0] LCP: auth: peer wants CHAP, I want nothing
May 16 11:57:48 pfsense2 ppp: [opt3_link0] LCP: LayerUp
May 16 11:57:48 pfsense2 ppp: [opt3_link0] LCP: rec'd Discard Request #3 (Opened)
May 16 11:57:48 pfsense2 ppp: [opt3_link0] CHAP: rec'd CHALLENGE #1 len: 35
May 16 11:57:48 pfsense2 ppp: [opt3_link0] Name: "UMTS_CHAP_SRVR"
May 16 11:57:48 pfsense2 ppp: [opt3_link0] CHAP: Using authname "user"
May 16 11:57:48 pfsense2 ppp: [opt3_link0] CHAP: sending RESPONSE #1 len: 25
May 16 11:57:48 pfsense2 ppp: [opt3_link0] CHAP: rec'd SUCCESS #1 len: 4
May 16 11:57:48 pfsense2 ppp: [opt3_link0] LCP: authorization successful
May 16 11:57:48 pfsense2 ppp: [opt3_link0] Link: Matched action 'bundle "opt3" ""'
May 16 11:57:48 pfsense2 ppp: [opt3_link0] Link: Join bundle "opt3"
May 16 11:57:48 pfsense2 ppp: [opt3] Bundle: Status update: up 1 link, total bandwidth 28800 bps
May 16 11:57:48 pfsense2 ppp: [opt3] IPCP: Open event
May 16 11:57:48 pfsense2 ppp: [opt3] IPCP: state change Initial --> Starting
May 16 11:57:48 pfsense2 ppp: [opt3] IPCP: LayerStart
May 16 11:57:48 pfsense2 ppp: [opt3] IPV6CP: Open event
May 16 11:57:48 pfsense2 ppp: [opt3] IPV6CP: state change Initial --> Starting
May 16 11:57:48 pfsense2 ppp: [opt3] IPV6CP: LayerStart
May 16 11:57:48 pfsense2 ppp: [opt3] IPCP: Up event
May 16 11:57:48 pfsense2 ppp: [opt3] IPCP: state change Starting --> Req-Sent
May 16 11:57:48 pfsense2 ppp: [opt3] IPCP: SendConfigReq #1
May 16 11:57:48 pfsense2 ppp: [opt3] IPADDR 0.0.0.0
May 16 11:57:48 pfsense2 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
May 16 11:57:48 pfsense2 ppp: [opt3] PRIDNS 0.0.0.0
May 16 11:57:48 pfsense2 ppp: [opt3] SECDNS 0.0.0.0
May 16 11:57:48 pfsense2 ppp: [opt3] IPV6CP: Up event
May 16 11:57:48 pfsense2 ppp: [opt3] IPV6CP: state change Starting --> Req-Sent
May 16 11:57:48 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #1
May 16 11:57:50 pfsense2 ppp: [opt3] IPCP: SendConfigReq #2
May 16 11:57:50 pfsense2 ppp: [opt3] IPADDR 0.0.0.0
May 16 11:57:50 pfsense2 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
May 16 11:57:50 pfsense2 ppp: [opt3] PRIDNS 0.0.0.0
May 16 11:57:50 pfsense2 ppp: [opt3] SECDNS 0.0.0.0
May 16 11:57:50 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #2
May 16 11:57:52 pfsense2 ppp: [opt3] IPCP: SendConfigReq #3
May 16 11:57:52 pfsense2 ppp: [opt3] IPADDR 0.0.0.0
May 16 11:57:52 pfsense2 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
May 16 11:57:52 pfsense2 ppp: [opt3] PRIDNS 0.0.0.0
May 16 11:57:52 pfsense2 ppp: [opt3] SECDNS 0.0.0.0
May 16 11:57:52 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #3
May 16 11:57:54 pfsense2 ppp: [opt3] IPCP: SendConfigReq #4
May 16 11:57:54 pfsense2 ppp: [opt3] IPADDR 0.0.0.0
May 16 11:57:54 pfsense2 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
May 16 11:57:54 pfsense2 ppp: [opt3] PRIDNS 0.0.0.0
May 16 11:57:54 pfsense2 ppp: [opt3] SECDNS 0.0.0.0
May 16 11:57:54 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #4
May 16 11:57:56 pfsense2 ppp: [opt3] IPCP: SendConfigReq #5
May 16 11:57:56 pfsense2 ppp: [opt3] IPADDR 0.0.0.0
May 16 11:57:56 pfsense2 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
May 16 11:57:56 pfsense2 ppp: [opt3] PRIDNS 0.0.0.0
May 16 11:57:56 pfsense2 ppp: [opt3] SECDNS 0.0.0.0
May 16 11:57:56 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #5
May 16 11:57:58 pfsense2 ppp: [opt3] IPCP: SendConfigReq #6
May 16 11:57:58 pfsense2 ppp: [opt3] IPADDR 0.0.0.0
May 16 11:57:58 pfsense2 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
May 16 11:57:58 pfsense2 ppp: [opt3] PRIDNS 0.0.0.0
May 16 11:57:58 pfsense2 ppp: [opt3] SECDNS 0.0.0.0
May 16 11:57:58 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #6
May 16 11:58:00 pfsense2 ppp: [opt3] IPCP: SendConfigReq #7
May 16 11:58:00 pfsense2 ppp: [opt3] IPADDR 0.0.0.0
May 16 11:58:00 pfsense2 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
May 16 11:58:00 pfsense2 ppp: [opt3] PRIDNS 0.0.0.0
May 16 11:58:00 pfsense2 ppp: [opt3] SECDNS 0.0.0.0
May 16 11:58:00 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #7
May 16 11:58:02 pfsense2 ppp: [opt3] IPCP: SendConfigReq #8
May 16 11:58:02 pfsense2 ppp: [opt3] IPADDR 0.0.0.0
May 16 11:58:02 pfsense2 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
May 16 11:58:02 pfsense2 ppp: [opt3] PRIDNS 0.0.0.0
May 16 11:58:02 pfsense2 ppp: [opt3] SECDNS 0.0.0.0
May 16 11:58:02 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #8
May 16 11:58:04 pfsense2 ppp: [opt3] IPCP: SendConfigReq #9
May 16 11:58:04 pfsense2 ppp: [opt3] IPADDR 0.0.0.0
May 16 11:58:04 pfsense2 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
May 16 11:58:04 pfsense2 ppp: [opt3] PRIDNS 0.0.0.0
May 16 11:58:04 pfsense2 ppp: [opt3] SECDNS 0.0.0.0
May 16 11:58:04 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #9
May 16 11:58:06 pfsense2 ppp: [opt3] IPCP: SendConfigReq #10
May 16 11:58:06 pfsense2 ppp: [opt3] IPADDR 0.0.0.0
May 16 11:58:06 pfsense2 ppp: [opt3] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
May 16 11:58:06 pfsense2 ppp: [opt3] PRIDNS 0.0.0.0
May 16 11:58:06 pfsense2 ppp: [opt3] SECDNS 0.0.0.0
May 16 11:58:06 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #10
May 16 11:58:08 pfsense2 ppp: [opt3_link0] LCP: no reply to 1 echo request(s)
May 16 11:58:08 pfsense2 ppp: [opt3] IPCP: parameter negotiation failed
May 16 11:58:08 pfsense2 ppp: [opt3] IPCP: state change Req-Sent --> Stopped
May 16 11:58:08 pfsense2 ppp: [opt3] IPCP: LayerFinish
May 16 11:58:08 pfsense2 ppp: [opt3] IPV6CP: parameter negotiation failed
May 16 11:58:08 pfsense2 ppp: [opt3] IPV6CP: state change Req-Sent --> Stopped
May 16 11:58:08 pfsense2 ppp: [opt3] IPV6CP: LayerFinish
May 16 11:58:08 pfsense2 ppp: [opt3] Bundle: No NCPs left. Closing links...
May 16 11:58:08 pfsense2 ppp: [opt3] Bundle: closing link "opt3_link0"...
May 16 11:58:08 pfsense2 ppp: [opt3_link0] Link: CLOSE event
May 16 11:58:08 pfsense2 ppp: [opt3_link0] LCP: Close event
May 16 11:58:08 pfsense2 ppp: [opt3_link0] LCP: state change Opened --> Closing
May 16 11:58:08 pfsense2 ppp: [opt3_link0] Link: Leave bundle "opt3"
May 16 11:58:08 pfsense2 ppp: [opt3] Bundle: Status update: up 0 links, total bandwidth 9600 bps
May 16 11:58:08 pfsense2 ppp: [opt3] IPCP: Close event
May 16 11:58:08 pfsense2 ppp: [opt3] IPCP: state change Stopped --> Closed
May 16 11:58:08 pfsense2 ppp: [opt3] IPV6CP: Close event
May 16 11:58:08 pfsense2 ppp: [opt3] IPV6CP: state change Stopped --> Closed
May 16 11:58:08 pfsense2 ppp: [opt3] IPCP: Down event
May 16 11:58:08 pfsense2 ppp: [opt3] IPCP: state change Closed --> Initial
May 16 11:58:08 pfsense2 ppp: [opt3] IPV6CP: Down event
May 16 11:58:08 pfsense2 ppp: [opt3] IPV6CP: state change Closed --> Initial
May 16 11:58:08 pfsense2 ppp: [opt3_link0] LCP: SendTerminateReq #2
May 16 11:58:08 pfsense2 ppp: [opt3_link0] LCP: LayerDown
May 16 11:58:10 pfsense2 ppp: [opt3_link0] LCP: SendTerminateReq #3
May 16 11:58:12 pfsense2 ppp: [opt3_link0] LCP: state change Closing --> Closed
May 16 11:58:12 pfsense2 ppp: [opt3_link0] LCP: LayerFinish
May 16 11:58:12 pfsense2 ppp: [opt3_link0] Link: DOWN event
May 16 11:58:12 pfsense2 ppp: [opt3_link0] LCP: Down event
May 16 11:58:12 pfsense2 ppp: [opt3_link0] LCP: state change Closed --> Initial


After the apparently successful CHAP exchange the conversation seems to become very one-sided - the network side seems to stop talking. An internet search showed a number of reports that Virgin Mobile demands PAP authentication.

In contrast, a trace of successful connection using the same modem on a Ubuntu 12.04 system:```

$ more ppp.log 
May 16 11:51:18 NetworkManager[840]: <info>pppd started with pid 19253
May 16 11:51:18 pppd[19253]: Plugin /usr/lib/pppd/2.4.5/nm-pppd-plugin.so loaded.
May 16 11:51:18 pppd[19253]: pppd 2.4.5 started by root, uid 0
May 16 11:51:18 pppd[19253]: using channel 4
May 16 11:51:18 NetworkManager[840]:    SCPlugin-Ifupdown: devices added (path: /sys/devices/virtual/net/ppp0, iface: ppp0)
May 16 11:51:18 NetworkManager[840]:    SCPlugin-Ifupdown: device added (path: /sys/devices/virtual/net/ppp0, iface: ppp0): no ifupdown configuration found.
May 16 11:51:18 pppd[19253]: Using interface ppp0
May 16 11:51:18 pppd[19253]: Connect: ppp0 <--> /dev/ttyUSB0
May 16 11:51:18 pppd[19253]: sent [LCP ConfReq id=0x1 <asyncmap 0x0=""><magic 0x4e9cf9c6=""><pcomp><accomp>]
May 16 11:51:18 pppd[19253]: rcvd [LCP ConfReq id=0x4 <asyncmap 0x0=""><auth chap="" md5=""><magic 0xfd49ad=""><pcomp><accomp>]
May 16 11:51:18 pppd[19253]: sent [LCP ConfNak id=0x4 <auth pap="">]
May 16 11:51:18 pppd[19253]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0=""><magic 0x4e9cf9c6=""><pcomp><accomp>]
May 16 11:51:18 pppd[19253]: rcvd [LCP ConfReq id=0x5 <asyncmap 0x0=""><auth pap=""><magic 0xfd49ad=""><pcomp><accomp>]
May 16 11:51:18 pppd[19253]: sent [LCP ConfAck id=0x5 <asyncmap 0x0=""><auth pap=""><magic 0xfd49ad=""><pcomp><accomp>]
May 16 11:51:18 pppd[19253]: sent [PAP AuthReq id=0x1 user="" password=<hidden>]
May 16 11:51:18 pppd[19253]: rcvd [LCP DiscReq id=0x6 magic=0xfd49ad]
May 16 11:51:18 pppd[19253]: rcvd [PAP AuthAck id=0x1 ""]
May 16 11:51:18 pppd[19253]: PAP authentication succeeded
May 16 11:51:18 pppd[19253]: sent [CCP ConfReq id=0x1 <deflate 15=""><deflate(old#) 15=""><bsd 15="" v1="">]
May 16 11:51:18 pppd[19253]: sent [IPCP ConfReq id=0x1 <compress vj="" 0f="" 01=""><addr 0.0.0.0=""><ms-dns1 0.0.0.0=""><ms-dns2 0.0.0.0="">]
May 16 11:51:18 pppd[19253]: rcvd [LCP ProtRej id=0x7 80 fd 01 01 00 0f 1a 04 78 00 18 04 78 00 15 03 2f]
May 16 11:51:18 pppd[19253]: Protocol-Reject for 'Compression Control Protocol' (0x80fd) received
May 16 11:51:21 pppd[19253]: sent [IPCP ConfReq id=0x1 <compress vj="" 0f="" 01=""><addr 0.0.0.0=""><ms-dns1 0.0.0.0=""><ms-dns2 0.0.0.0="">]
May 16 11:51:21 pppd[19253]: rcvd [IPCP ConfReq id=0x2]
May 16 11:51:21 pppd[19253]: sent [IPCP ConfNak id=0x2 <addr 0.0.0.0="">]
May 16 11:51:21 pppd[19253]: rcvd [IPCP ConfRej id=0x1 <compress vj="" 0f="" 01="">]
May 16 11:51:21 pppd[19253]: sent [IPCP ConfReq id=0x2 <addr 0.0.0.0=""><ms-dns1 0.0.0.0=""><ms-dns2 0.0.0.0="">]
May 16 11:51:21 pppd[19253]: rcvd [IPCP ConfReq id=0x3]
May 16 11:51:21 pppd[19253]: sent [IPCP ConfAck id=0x3]
May 16 11:51:21 pppd[19253]: rcvd [IPCP ConfNak id=0x2 <addr 119.12.235.83=""><ms-dns1 123.200.191.17=""><ms-dns2 123.200.191.18="">]
May 16 11:51:21 pppd[19253]: sent [IPCP ConfReq id=0x3 <addr 119.12.235.83=""><ms-dns1 123.200.191.17=""><ms-dns2 123.200.191.18="">]
May 16 11:51:21 pppd[19253]: rcvd [IPCP ConfAck id=0x3 <addr 119.12.235.83=""><ms-dns1 123.200.191.17=""><ms-dns2 123.200.191.18="">]
May 16 11:51:21 pppd[19253]: Could not determine remote IP address: defaulting to 10.64.64.64
May 16 11:51:21 pppd[19253]: local  IP address 119.12.235.83
May 16 11:51:21 pppd[19253]: remote IP address 10.64.64.64
May 16 11:51:21 pppd[19253]: primary   DNS address 123.200.191.17
May 16 11:51:21 pppd[19253]: secondary DNS address 123.200.191.18
May 16 11:51:21 pppd[19253]: Script /etc/ppp/ip-up started (pid 19256)
May 16 11:51:22 NetworkManager[840]: <info>(ppp0): writing resolv.conf to /sbin/resolvconf
May 16 11:51:26 pppd[19253]: Script /etc/ppp/ip-up finished (pid 19256), status = 0x0</info></ms-dns2></ms-dns1></addr></ms-dns2></ms-dns1></addr></ms-dns2></ms-dns1></addr></ms-dns2></ms-dns1></addr></compress></addr></ms-dns2></ms-dns1></addr></compress></ms-dns2></ms-dns1></addr></compress></bsd></deflate(old#)></deflate></hidden></accomp></pcomp></magic></auth></asyncmap></accomp></pcomp></magic></auth></asyncmap></accomp></pcomp></magic></asyncmap></auth></accomp></pcomp></magic></auth></asyncmap></accomp></pcomp></magic></asyncmap></info>

pfSense mpd reports it is version 5.6. Documentation for mpd 5.6 is currently at http://mpd.sourceforge.net/doc5/mpd.html

My 3g modem is pfSense interface opt3 and its configuration is in /var/etc/mpd_opt3.conf which is regenerated every time opt3 is enabled. Therefore to change opt3 PPP parameters I needed to change the code in /etc/inc/interfaces.inc which generates mpd_opt3.conf.

I wanted to get enhanced logging to get more details of the PPP initialisation so I changed the line```

#log -bund -cccp -chat -iface -ipcp -lcp -link

to

log +bund* +ccp* +chat* +iface* +ipcp* +lcp* +link*


Next I changed```

    set link disable chap pap
    set link accept chap pap eap

```to```

    set link deny chap pap chap-md5 chap-msv1 chap-msv2 eap
    set link accept pap

to deny the network's attempt to use any authentication EXCEPT pap.

I also noticed that the /var/etc/mpd_opt3.conf had three non-printing characters as the PPP password even though a null username and password had specified in the web GUI. While poking around in /etc/inc/interfaces.inc I noticed```

if (empty($ppp['username']) && $type == "modem"){
$ppp['username'] = "user";
$ppp['password'] = "none";
}
if (empty($ppp['password']) && $type == "modem")
$passwd = "none";
else
$passwd = base64_decode($ppp['password']);

which if $ppp['username'] is empty sets $ppp['password] to "none" and then $passwd to base64_decode("none") - three non-printing characters. I commented out```

$ppp['password'] = "none";

```so $passwd would be set to "none" if $ppp['password'] is empty.

After these changes PPP initialisation completes```

May 16 12:52:57 pfsense2 ppp: Multi-link PPP daemon for FreeBSD
May 16 12:52:57 pfsense2 ppp:  
May 16 12:52:57 pfsense2 ppp: process 24037 started, version 5.6 (root@FreeBSD_8.3_pfSense_2.1.snaps.pfsense.org 13:36  1-May-2012)
May 16 12:52:57 pfsense2 ppp: web: web is not running
May 16 12:52:57 pfsense2 ppp: [opt3] Bundle: Interface ng0 created
May 16 12:52:57 pfsense2 ppp: [opt3_link0] Link: OPEN event
May 16 12:52:57 pfsense2 ppp: [opt3_link0] LCP: Open event
May 16 12:52:57 pfsense2 ppp: [opt3_link0] LCP: state change Initial --> Starting
May 16 12:52:57 pfsense2 ppp: [opt3_link0] LCP: LayerStart
May 16 12:52:57 pfsense2 ppp: [opt3_link0] CHAT: Detected Hayes compatible modem.
May 16 12:52:57 pfsense2 ppp: [opt3_link0] CHAT: Sending Custom init
May 16 12:52:57 pfsense2 ppp: [opt3_link0] CHAT: OK
May 16 12:52:57 pfsense2 ppp: [opt3_link0] CHAT: Dialing server at *99#...
May 16 12:52:57 pfsense2 ppp: [opt3_link0] CHAT: Connected at an unknown speed.
May 16 12:52:57 pfsense2 ppp: [opt3_link0] MODEM: chat script succeeded
May 16 12:52:57 pfsense2 ppp: [opt3_link0] Link: UP event
May 16 12:52:57 pfsense2 ppp: [opt3_link0] LCP: Up event
May 16 12:52:57 pfsense2 ppp: [opt3_link0] LCP: state change Starting --> Req-Sent
May 16 12:52:57 pfsense2 ppp: [opt3_link0] LCP: SendConfigReq #1
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   ACFCOMP
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   PROTOCOMP
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   ACCMAP 0x000a0000
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   MRU 1500
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   MAGICNUM b2e41852
May 16 12:52:57 pfsense2 ppp: [opt3_link0] LCP: rec'd Configure Request #0 (Req-Sent)
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   ACCMAP 0x00000000
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   AUTHPROTO CHAP MD5
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   MAGICNUM 00f5ba75
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   PROTOCOMP
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   ACFCOMP
May 16 12:52:57 pfsense2 ppp: [opt3_link0] LCP: SendConfigNak #0
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   AUTHPROTO PAP
May 16 12:52:57 pfsense2 ppp: [opt3_link0] LCP: rec'd Configure Ack #1 (Req-Sent)
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   ACFCOMP
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   PROTOCOMP
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   ACCMAP 0x000a0000
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   MRU 1500
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   MAGICNUM b2e41852
May 16 12:52:57 pfsense2 ppp: [opt3_link0] LCP: state change Req-Sent --> Ack-Rcvd
May 16 12:52:57 pfsense2 ppp: [opt3_link0] LCP: rec'd Configure Request #1 (Ack-Rcvd)
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   ACCMAP 0x00000000
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   AUTHPROTO PAP
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   MAGICNUM 00f5ba75
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   PROTOCOMP
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   ACFCOMP
May 16 12:52:57 pfsense2 ppp: [opt3_link0] LCP: SendConfigAck #1
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   ACCMAP 0x00000000
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   AUTHPROTO PAP
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   MAGICNUM 00f5ba75
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   PROTOCOMP
May 16 12:52:57 pfsense2 ppp: [opt3_link0]   ACFCOMP
May 16 12:52:57 pfsense2 ppp: [opt3_link0] LCP: state change Ack-Rcvd --> Opened
May 16 12:52:57 pfsense2 ppp: [opt3_link0] LCP: auth: peer wants PAP, I want nothing
May 16 12:52:57 pfsense2 ppp: [opt3_link0] PAP: using authname "user"
May 16 12:52:57 pfsense2 ppp: [opt3_link0] PAP: sending REQUEST #1 len: 14
May 16 12:52:57 pfsense2 ppp: [opt3_link0] LCP: LayerUp
May 16 12:52:57 pfsense2 ppp: [opt3_link0] LCP: rec'd Discard Request #2 (Opened)
May 16 12:52:57 pfsense2 ppp: [opt3_link0] PAP: rec'd ACK #1 len: 5
May 16 12:52:57 pfsense2 ppp: [opt3_link0] LCP: authorization successful
May 16 12:52:57 pfsense2 ppp: [opt3_link0] Link: Matched action 'bundle "opt3" ""'
May 16 12:52:57 pfsense2 ppp: [opt3_link0] Link: Join bundle "opt3"
May 16 12:52:57 pfsense2 ppp: [opt3] Bundle: Status update: up 1 link, total bandwidth 28800 bps
May 16 12:52:57 pfsense2 ppp: [opt3] IPCP: Open event
May 16 12:52:57 pfsense2 ppp: [opt3] IPCP: state change Initial --> Starting
May 16 12:52:57 pfsense2 ppp: [opt3] IPCP: LayerStart
May 16 12:52:57 pfsense2 ppp: [opt3] IPV6CP: Open event
May 16 12:52:57 pfsense2 ppp: [opt3] IPV6CP: state change Initial --> Starting
May 16 12:52:57 pfsense2 ppp: [opt3] IPV6CP: LayerStart
May 16 12:52:57 pfsense2 ppp: [opt3] IPCP: Up event
May 16 12:52:57 pfsense2 ppp: [opt3] IPCP: state change Starting --> Req-Sent
May 16 12:52:57 pfsense2 ppp: [opt3] IPCP: SendConfigReq #1
May 16 12:52:57 pfsense2 ppp: [opt3]   IPADDR 0.0.0.0
May 16 12:52:57 pfsense2 ppp: [opt3]   COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
May 16 12:52:57 pfsense2 ppp: [opt3]   PRIDNS 0.0.0.0
May 16 12:52:57 pfsense2 ppp: [opt3]   SECDNS 0.0.0.0
May 16 12:52:57 pfsense2 ppp: [opt3] IPV6CP: Up event
May 16 12:52:57 pfsense2 ppp: [opt3] IPV6CP: state change Starting --> Req-Sent
May 16 12:52:57 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #1
May 16 12:52:59 pfsense2 ppp: [opt3] IPCP: SendConfigReq #2
May 16 12:52:59 pfsense2 ppp: [opt3]   IPADDR 0.0.0.0
May 16 12:52:59 pfsense2 ppp: [opt3]   COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
May 16 12:52:59 pfsense2 ppp: [opt3]   PRIDNS 0.0.0.0
May 16 12:52:59 pfsense2 ppp: [opt3]   SECDNS 0.0.0.0
May 16 12:52:59 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #2
May 16 12:53:00 pfsense2 ppp: [opt3] IPCP: rec'd Configure Request #0 (Req-Sent)
May 16 12:53:00 pfsense2 ppp: [opt3] IPCP: SendConfigAck #0
May 16 12:53:00 pfsense2 ppp: [opt3] IPCP: state change Req-Sent --> Ack-Sent
May 16 12:53:00 pfsense2 ppp: [opt3] IPCP: rec'd Configure Reject #2 (Ack-Sent)
May 16 12:53:00 pfsense2 ppp: [opt3]   COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
May 16 12:53:00 pfsense2 ppp: [opt3] IPCP: SendConfigReq #3
May 16 12:53:00 pfsense2 ppp: [opt3]   IPADDR 0.0.0.0
May 16 12:53:00 pfsense2 ppp: [opt3]   PRIDNS 0.0.0.0
May 16 12:53:00 pfsense2 ppp: [opt3]   SECDNS 0.0.0.0
May 16 12:53:00 pfsense2 ppp: [opt3] IPCP: rec'd Configure Nak #3 (Ack-Sent)
May 16 12:53:00 pfsense2 ppp: [opt3]   IPADDR 123.200.238.143
May 16 12:53:00 pfsense2 ppp: [opt3]     123.200.238.143 is OK
May 16 12:53:00 pfsense2 ppp: [opt3]   PRIDNS 123.200.191.17
May 16 12:53:00 pfsense2 ppp: [opt3]   SECDNS 123.200.191.18
May 16 12:53:00 pfsense2 ppp: [opt3] IPCP: SendConfigReq #4
May 16 12:53:00 pfsense2 ppp: [opt3]   IPADDR 123.200.238.143
May 16 12:53:00 pfsense2 ppp: [opt3]   PRIDNS 123.200.191.17
May 16 12:53:00 pfsense2 ppp: [opt3]   SECDNS 123.200.191.18
May 16 12:53:00 pfsense2 ppp: [opt3] IPCP: rec'd Configure Ack #4 (Ack-Sent)
May 16 12:53:00 pfsense2 ppp: [opt3]   IPADDR 123.200.238.143
May 16 12:53:00 pfsense2 ppp: [opt3]   PRIDNS 123.200.191.17
May 16 12:53:00 pfsense2 ppp: [opt3]   SECDNS 123.200.191.18
May 16 12:53:00 pfsense2 ppp: [opt3] IPCP: state change Ack-Sent --> Opened
May 16 12:53:00 pfsense2 ppp: [opt3] IPCP: LayerUp
May 16 12:53:00 pfsense2 ppp: [opt3]   123.200.238.143 -> 10.64.64.0
May 16 12:53:01 pfsense2 ppp: [opt3] IFACE: Up event
May 16 12:53:01 pfsense2 ppp: [opt3] IFACE: Rename interface ng0 to ppp0
May 16 12:53:02 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #3
May 16 12:53:04 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #4
May 16 12:53:06 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #5
May 16 12:53:08 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #6
May 16 12:53:10 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #7
May 16 12:53:12 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #8
May 16 12:53:14 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #9
May 16 12:54:33 pfsense2 ppp: [opt3] IPV6CP: SendConfigReq #10
May 16 12:54:35 pfsense2 ppp: [opt3] IPV6CP: parameter negotiation failed
May 16 12:54:35 pfsense2 ppp: [opt3] IPV6CP: state change Req-Sent --> Stopped
May 16 12:54:35 pfsense2 ppp: [opt3] IPV6CP: LayerFinish

Nicely solved ! I read about that Multimegabit downstream in Australia in another post - I sometimes dream about this would be possible in Germany too. (hsupa wt max 1m down in Frankfurt… If you are curious, i opened another thread about a plan to implement an editable mpd_[interface].conf in
http://forum.pfsense.org/index.php/topic,49478.0.html

hanD :)