Fatal error when using Huawei E1820 USB 3G modem



  • The last few days I've been trying to get a Huawei E1820 3G USB modem working with pfSense. I have not been able to get a working connection using pfSense, but the modem works OK in Win XP and Ubuntu. I have tested both 32 and 64 bit versions of pfSense, with a couple of snapshots, the latest being pfSense-2.0-BETA4-20100925-1629. Testing hardware is an Intel D510MO motherboard with 2 GB RAM and an 80 GB HDD.

    Huawei E1820 is a HSPA+ 3G modem that reports itself as vendor=0x12d1 product=0x1446 before modeswitch and as product=0x14ac after, according to available data. The modem seem to modeswitch ok, indicated by the product id.

    devinfo -rv | grep u3g
    u3g0 pnpinfo vendor=0x12d1 product=0x14ac devclass=0x00 devsubclass=0x00 sernum="" release=0x0000 intclass=0xff intsubclass=0xff at bus=1 hubaddr=1 port=4 devaddr=2 interface=0

    ls /dev/cua* reports the following available ports:
    cuaU0.0, cuaU0.1, cuaU0.2, cuaU0.3, cuau0, cuau1

    There is something strange with the detection of the working ports (ports responding to AT command), in most cases only cuaU0.3 is available under Interfaces > Assign > PPP though occasionally both cuaU0.0 and cuaU0.3 are available.

    Initially I thought that the cuaU0.3 port was the correct port for communication, the problem was that the dial response always was "The remote modem did not answer" in ppp.log. Trying to dial manually always resulted in a "NO CARRIER" response.

    After some trial and error I found out that when configuring PPP to use cuaU0.0 there was almost a connection after a reboot. cuaU0.0 seem to be the correct port to use. Unfortunately, trying to communicate through cuaU0.3 seem to stop cuaU0.0 from responding, a fact that made the fault finding rather lengthy (and could have something to do with the strange port detection mentioned above). However when I got the port correctly configured, a fatal error shows up that makes it impossible to get the link working, see ppp.log.

    Anybody got any ideas or solutions to this problem?

    ppp.log:

    Sep 26 21:51:32 pfSense ppp: [wan_link0] Link: reconnection attempt 9
    Sep 26 21:51:32 pfSense ppp: [wan_link0] chat: Detected Hayes compatible modem.
    Sep 26 21:51:32 pfSense ppp: [wan_link0] chat: Dialing server at *99#...
    Sep 26 21:51:32 pfSense ppp: [wan_link0] chat: Connected at 21600000.
    Sep 26 21:51:32 pfSense ppp: [wan_link0] MODEM: chat script succeeded
    Sep 26 21:51:32 pfSense ppp: [wan_link0] Link: UP event
    Sep 26 21:51:32 pfSense ppp: [wan_link0] LCP: Up event
    Sep 26 21:51:32 pfSense ppp: [wan_link0] LCP: state change Starting --> Req-Sent
    Sep 26 21:51:32 pfSense ppp: [wan_link0] LCP: SendConfigReq #1
    Sep 26 21:51:32 pfSense ppp: [wan_link0]   ACFCOMP
    Sep 26 21:51:32 pfSense ppp: [wan_link0]   PROTOCOMP
    Sep 26 21:51:32 pfSense ppp: [wan_link0]   ACCMAP 0x000a0000
    Sep 26 21:51:32 pfSense ppp: [wan_link0]   MRU 1500
    Sep 26 21:51:32 pfSense ppp: [wan_link0]   MAGICNUM 038a178c
    Sep 26 21:51:32 pfSense ppp: [wan_link0] LCP: rec'd Configure Request #0 (Req-Sent)
    Sep 26 21:51:32 pfSense ppp: [wan_link0]   ACCMAP 0x00000000
    Sep 26 21:51:32 pfSense ppp: [wan_link0]   AUTHPROTO CHAP MD5
    Sep 26 21:51:32 pfSense ppp: [wan_link0]   MAGICNUM 02d84a08
    Sep 26 21:51:32 pfSense ppp: [wan_link0]   PROTOCOMP
    Sep 26 21:51:32 pfSense ppp: [wan_link0]   ACFCOMP
    Sep 26 21:51:32 pfSense ppp: [wan_link0] LCP: SendConfigAck #0
    Sep 26 21:51:32 pfSense ppp: [wan_link0]   ACCMAP 0x00000000
    Sep 26 21:51:32 pfSense ppp: [wan_link0]   AUTHPROTO CHAP MD5
    Sep 26 21:51:32 pfSense ppp: [wan_link0]   MAGICNUM 02d84a08
    Sep 26 21:51:32 pfSense ppp: [wan_link0]   PROTOCOMP
    Sep 26 21:51:32 pfSense ppp: [wan_link0]   ACFCOMP
    Sep 26 21:51:32 pfSense ppp: [wan_link0] LCP: state change Req-Sent --> Ack-Sent
    Sep 26 21:51:32 pfSense ppp: [wan_link0] LCP: rec'd Configure Ack #1 (Ack-Sent)
    Sep 26 21:51:32 pfSense ppp: [wan_link0]   ACFCOMP
    Sep 26 21:51:32 pfSense ppp: [wan_link0]   PROTOCOMP
    Sep 26 21:51:32 pfSense ppp: [wan_link0]   ACCMAP 0x000a0000
    Sep 26 21:51:32 pfSense ppp: [wan_link0]   MRU 1500
    Sep 26 21:51:32 pfSense ppp: [wan_link0]   MAGICNUM 038a178c
    Sep 26 21:51:32 pfSense ppp: [wan_link0] LCP: state change Ack-Sent --> Opened
    Sep 26 21:51:32 pfSense ppp: [wan_link0] LCP: auth: peer wants CHAP, I want nothing
    Sep 26 21:51:32 pfSense ppp: [wan_link0] LCP: LayerUp
    Sep 26 21:51:32 pfSense ppp: [wan_link0] LCP: rec'd Discard Request #1 (Opened)
    Sep 26 21:51:32 pfSense ppp: [wan_link0] CHAP: rec'd CHALLENGE #1 len: 35
    Sep 26 21:51:32 pfSense ppp: [wan_link0]   Name: "UMTS_CHAP_SRVR"
    Sep 26 21:51:32 pfSense ppp: [wan_link0] CHAP: Using authname "none"
    Sep 26 21:51:32 pfSense ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 25
    Sep 26 21:51:32 pfSense ppp: [wan_link0] CHAP: rec'd SUCCESS #1 len: 4
    Sep 26 21:51:32 pfSense ppp: [wan_link0] LCP: authorization successful
    Sep 26 21:51:32 pfSense ppp: [wan_link0] Link: Matched action 'bundle "wan" ""'
    Sep 26 21:51:32 pfSense ppp: [wan_link0] Link: Join bundle "wan"
    Sep 26 21:51:32 pfSense ppp: [wan] Bundle: Status update: up 1 link, total bandwidth 21600000 bps
    Sep 26 21:51:32 pfSense ppp: [wan] can't config [c]:: Invalid argument
    Sep 26 21:51:32 pfSense ppp: fatal error, exiting
    Sep 26 21:51:32 pfSense ppp: [wan] IFACE: Close event
    Sep 26 21:51:32 pfSense ppp: [wan] IPCP: Close event
    Sep 26 21:51:32 pfSense ppp: [wan] Bundle: Shutdown
    Sep 26 21:51:32 pfSense ppp: [wan_link0] Link: Shutdown
    Sep 26 21:51:32 pfSense ppp: process 7062 terminated
    

    dmesg:

    ugen4.2: <huawei technologies=""> at usbus4
    ugen4.2: <huawei technologies=""> at usbus4 (disconnected)
    ugen4.2: <huawei technologies=""> at usbus4
    u3g0: <huawei 0="" 2="" technologies="" huawei="" mobile,="" class="" 0,="" rev="" 2.00="" 0.00,="" addr=""> on usbus4
    u3g0: Found 4 ports.
    umass0: <huawei 0="" 2="" technologies="" huawei="" mobile,="" class="" 0,="" rev="" 2.00="" 0.00,="" addr=""> on usbus4
    umass0:  SCSI over Bulk-Only; quirks = 0x0000
    umass0:0:0:-1: Attached to scbus0
    umass1: <huawei 0="" 2="" technologies="" huawei="" mobile,="" class="" 0,="" rev="" 2.00="" 0.00,="" addr=""> on usbus4
    umass1:  SCSI over Bulk-Only; quirks = 0x0000
    (probe0:umass-sim0:0:0:0): TEST UNIT READY. CDB: 0 0 0 0 0 0 
    (probe0:umass-sim0:0:0:0): CAM status: SCSI Status Error
    (probe0:umass-sim0:0:0:0): SCSI status: Check Condition
    (probe0:umass-sim0:0:0:0): SCSI sense: NOT READY asc:3a,0 (Medium not present)
    cd0 at umass-sim0 bus 0 scbus0 target 0 lun 0
    cd0: <huawei mass="" storage="" 2.31=""> Removable CD-ROM SCSI-2 device 
    cd0: 40.000MB/s transfers
    cd0: Attempt to query device size failed: NOT READY, Medium not present
    umass1:1:1:-1: Attached to scbus1
    (probe0:umass-sim1:1:0:0): TEST UNIT READY. CDB: 0 0 0 0 0 0 
    (probe0:umass-sim1:1:0:0): CAM status: SCSI Status Error
    (probe0:umass-sim1:1:0:0): SCSI status: Check Condition
    (probe0:umass-sim1:1:0:0): SCSI sense: NOT READY asc:3a,0 (Medium not present)
    da0 at umass-sim1 bus 1 scbus1 target 0 lun 0
    da0: <huawei tf="" card="" storage=""> Removable Direct Access SCSI-2 device 
    da0: 40.000MB/s transfers
    da0: Attempt to query device size failed: NOT READY, Medium not present</huawei></huawei></huawei></huawei></huawei></huawei></huawei></huawei>
    


  • I'm having the same problem with my ZTE MF668 (Rogers Rocketstick).  Initially pfSense was detecting it only as USB storage, so I couldn't select it as an interface in the PPP menu.  I plugged the modem into a Windows computer and this is what it reported in Control Panel: USB\VID_19D2&PID_2000 (before driver install) and USB\VID_19D2&PID_0017&MI_02 (after driver install).

    My Linux knowledge is rather limited, and I wasn't sure how to make pfSense do the mode switch from storage to modem manually, so I connected to it using HyperTerminal in Windows and executed the command "AT+ZCDRUN=8".  I plugged it back into the pfSense computer and it does see it as a modem now.  I was able to set my PPP config using cuau0.2 as the interface, but I get the same error as ldtech describes above.  Here's a snippet from my PPP log:

    Oct 20 21:39:00 ppp: [wan_link0] ACFCOMP
    Oct 20 21:39:00 ppp: [wan_link0] PROTOCOMP
    Oct 20 21:39:00 ppp: [wan_link0] ACCMAP 0x000a0000
    Oct 20 21:39:00 ppp: [wan_link0] MRU 1500
    Oct 20 21:39:00 ppp: [wan_link0] MAGICNUM f3c54239
    Oct 20 21:39:00 ppp: [wan_link0] LCP: state change Ack-Sent –> Opened
    Oct 20 21:39:00 ppp: [wan_link0] LCP: auth: peer wants CHAP, I want nothing
    Oct 20 21:39:00 ppp: [wan_link0] LCP: LayerUp
    Oct 20 21:39:00 ppp: [wan_link0] LCP: rec'd Discard Request #1 (Opened)
    Oct 20 21:39:00 ppp: [wan_link0] CHAP: rec'd CHALLENGE #1 len: 35
    Oct 20 21:39:00 ppp: [wan_link0] Name: "UMTS_CHAP_SRVR"
    Oct 20 21:39:00 ppp: [wan_link0] CHAP: Using authname "wapuser1"
    Oct 20 21:39:00 ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 29
    Oct 20 21:39:00 ppp: [wan_link0] CHAP: rec'd SUCCESS #1 len: 4
    Oct 20 21:39:00 ppp: [wan_link0] LCP: authorization successful
    Oct 20 21:39:00 ppp: [wan_link0] Link: Matched action 'bundle "wan" ""'
    Oct 20 21:39:00 ppp: [wan_link0] Link: Join bundle "wan"
    Oct 20 21:39:00 ppp: [wan] Bundle: Status update: up 1 link, total bandwidth 21000000 bps
    Oct 20 21:39:00 ppp: [wan] can't config [c]:: Invalid argument
    Oct 20 21:39:00 ppp: fatal error, exiting
    Oct 20 21:39:00 ppp: [wan] IFACE: Close event
    Oct 20 21:39:00 ppp: [wan] IPCP: Close event
    Oct 20 21:39:00 ppp: [wan] Bundle: Shutdown
    Oct 20 21:39:00 ppp: [wan_link0] Link: Shutdown
    Oct 20 21:39:00 ppp: process 6903 terminated

    Everything seems to go wrong at the line Oct 20 21:39:00    ppp: [wan] can't config [c]:: Invalid argument

    Subsequent reconnection attempts get only this in the PPP log:

    Oct 20 21:31:27 ppp: [wan_link0] Link: reconnection attempt 10 in 3 seconds
    Oct 20 21:31:30 ppp: [wan_link0] Link: reconnection attempt 10
    Oct 20 21:31:30 ppp: [wan_link0] chat: Detected Hayes compatible modem.
    Oct 20 21:31:30 ppp: [wan_link0] chat: Dialing server at *99#…
    Oct 20 21:31:30 ppp: [wan_link0] chat: Invalid dial init string.
    Oct 20 21:31:30 ppp: [wan_link0] MODEM: chat script failed
    Oct 20 21:31:30 ppp: [wan_link0] Link: DOWN event
    Oct 20 21:31:30 ppp: [wan_link0] LCP: Down event

    Anyone know what this means?  Or have any direction of where I should begin troubleshooting?



  • Update

    Downloaded the latest beta snapshot (20101020) and I'm still getting an error at the same point but slightly different:

    ppp: [wan] can't config [19]:: Invalid argument



  • Can you get /var/etc/mpd_*.conf



  • Ok. tried again with snapshot 20101024.

    Here is the /var/etc/mpd_wan.conf:

    startup:

    configure the console

    set console close

    configure the web server

    set web close

    default:
    pppclient:
    create bundle static wan
    set iface name ppp1
    set iface route default
    set iface disable on-demand
    set iface idle 0
    set iface enable tcpmssfix
    set iface up-script /usr/local/sbin/ppp-linkup
    set iface down-script /usr/local/sbin/ppp-linkdown
    set ipcp ranges 0.0.0.0/0 10.64.64.0/0
    set ipcp enable req-pri-dns
    set ipcp enable req-sec-dns
    #log -bund -ccp -chat -iface -ipcp -lcp -link

    create link static wan_link0 modem
    set link action bundle wan
    set link disable multilink
    set link keep-alive 10 60
    set link max-redial 0
    set link disable chap pap
    set link accept chap pap eap
    set link disable incoming
    set link mtu 1492
    set auth authname "wapuser1"
    set auth password wap
    set modem device /dev/cuaU0.2
    set modem script DialPeer
    set modem idle-script Ringback
    set modem watch -cd
    set modem var $DialPrefix "DT"
    set modem var $Telephone "*99#"
    set modem var $APN "isp.apn"
    set modem var $APNum "1"
    open

    I still get the "ppp: [wan] can't config [c]:: Invalid argument", this time I also got another variation "ppp: [wan] can't config [33]:: Invalid argument".



  • Was a solution to this ever found?



  • This problem still exist in RC1 (i386-20110226-1429).

    I also noted that when trying to use two USB 3G modems only one connects, the other gets USB_ERR_TIMEOUT.

    RC1 is clearly not ready for production.



  • I also have the same problem with my Huawei 3g module.

    Is there a way to set the PPP debug level to MAX?

    pppd.log

    May 3 16:31:18	ppp: process 41455 terminated
    May 3 16:31:18	ppp: [opt2_link0] Link: Shutdown
    May 3 16:31:18	ppp: [opt2] Bundle: Shutdown
    May 3 16:31:18	ppp: [opt2] IPV6CP: Close event
    May 3 16:31:18	ppp: [opt2] IPCP: Close event
    May 3 16:31:18	ppp: [opt2] IFACE: Close event
    May 3 16:31:18	ppp: fatal error, exiting
    May 3 16:31:18	ppp: [opt2] can't config [7c]:: Invalid argument
    May 3 16:31:18	ppp: [opt2] Bundle: Status update: up 1 link, total bandwidth 28800000 bps
    May 3 16:31:18	ppp: [opt2_link0] Link: Join bundle "opt2"
    May 3 16:31:18	ppp: [opt2_link0] Link: Matched action 'bundle "opt2" ""'
    May 3 16:31:18	ppp: [opt2_link0] LCP: authorization successful
    May 3 16:31:18	ppp: [opt2_link0] CHAP: rec'd SUCCESS #1 len: 4
    May 3 16:31:18	ppp: [opt2_link0] CHAP: sending RESPONSE #1 len: 29
    May 3 16:31:18	ppp: [opt2_link0] CHAP: Using authname "vodafone"
    May 3 16:31:18	ppp: [opt2_link0] Name: "UMTS_CHAP_SRVR"
    May 3 16:31:18	ppp: [opt2_link0] CHAP: rec'd CHALLENGE #1 len: 35
    May 3 16:31:18	ppp: [opt2_link0] LCP: rec'd Discard Request #1 (Opened)
    May 3 16:31:18	ppp: [opt2_link0] LCP: LayerUp
    May 3 16:31:18	ppp: [opt2_link0] LCP: auth: peer wants CHAP, I want nothing
    May 3 16:31:18	ppp: [opt2_link0] LCP: state change Ack-Sent --> Opened
    May 3 16:31:18	ppp: [opt2_link0] MAGICNUM 7025c5a8
    May 3 16:31:18	ppp: [opt2_link0] MRU 1500
    May 3 16:31:18	ppp: [opt2_link0] ACCMAP 0x000a0000
    May 3 16:31:18	ppp: [opt2_link0] PROTOCOMP
    May 3 16:31:18	ppp: [opt2_link0] ACFCOMP
    May 3 16:31:18	ppp: [opt2_link0] LCP: rec'd Configure Ack #1 (Ack-Sent)
    May 3 16:31:18	ppp: [opt2_link0] LCP: state change Req-Sent --> Ack-Sent
    May 3 16:31:18	ppp: [opt2_link0] ACFCOMP
    May 3 16:31:18	ppp: [opt2_link0] PROTOCOMP
    May 3 16:31:18	ppp: [opt2_link0] MAGICNUM 02d92385
    May 3 16:31:18	ppp: [opt2_link0] AUTHPROTO CHAP MD5
    May 3 16:31:18	ppp: [opt2_link0] ACCMAP 0x00000000
    May 3 16:31:18	ppp: [opt2_link0] LCP: SendConfigAck #0
    May 3 16:31:18	ppp: [opt2_link0] ACFCOMP
    May 3 16:31:18	ppp: [opt2_link0] PROTOCOMP
    May 3 16:31:18	ppp: [opt2_link0] MAGICNUM 02d92385
    May 3 16:31:18	ppp: [opt2_link0] AUTHPROTO CHAP MD5
    May 3 16:31:18	ppp: [opt2_link0] ACCMAP 0x00000000
    May 3 16:31:18	ppp: [opt2_link0] LCP: rec'd Configure Request #0 (Req-Sent)
    May 3 16:31:18	ppp: [opt2_link0] MAGICNUM 7025c5a8
    May 3 16:31:18	ppp: [opt2_link0] MRU 1500
    May 3 16:31:18	ppp: [opt2_link0] ACCMAP 0x000a0000
    May 3 16:31:18	ppp: [opt2_link0] PROTOCOMP
    May 3 16:31:18	ppp: [opt2_link0] ACFCOMP
    May 3 16:31:18	ppp: [opt2_link0] LCP: SendConfigReq #1
    May 3 16:31:18	ppp: [opt2_link0] LCP: state change Starting --> Req-Sent
    May 3 16:31:18	ppp: [opt2_link0] LCP: Up event
    May 3 16:31:18	ppp: [opt2_link0] Link: UP event
    May 3 16:31:18	ppp: [opt2_link0] MODEM: chat script succeeded
    May 3 16:31:18	ppp: [opt2_link0] chat: Connected at 28800000.
    May 3 16:31:18	ppp: [opt2_link0] chat: Dialing server at *99#...
    May 3 16:31:18	ppp: [opt2_link0] chat: Detected Hayes compatible modem.
    May 3 16:31:18	ppp: [opt2_link0] LCP: LayerStart
    May 3 16:31:18	ppp: [opt2_link0] LCP: state change Initial --> Starting
    May 3 16:31:18	ppp: [opt2_link0] LCP: Open event
    May 3 16:31:18	ppp: [opt2_link0] Link: OPEN event
    May 3 16:31:18	ppp: [opt2] Bundle: Interface ng4 created
    May 3 16:31:18	ppp: web: web is not running
    May 3 16:31:18	ppp: process 41455 started, version 5.5 (root@bsd8x86.pingle.org 14:01 28-Feb-2011)
    May 3 16:31:18	ppp:
    May 3 16:31:18	ppp: Multi-link PPP daemon for FreeBSD
    

    /var/etc/mpd_3g.conf

    
    startup:
            # configure the console
            set console close
            # configure the web server
            set web close
    
    default:
    pppclient:
            create bundle static opt2
            set bundle enable ipv6cp
            set iface name ppp0
            set iface disable on-demand
            set iface idle 0
            set iface enable tcpmssfix
            set iface up-script /usr/local/sbin/ppp-linkup
            set iface down-script /usr/local/sbin/ppp-linkdown
            set ipcp ranges 0.0.0.0/0 10.64.64.0/0
            #log -bund -ccp -chat -iface -ipcp -lcp -link
    
            create link static opt2_link0 modem
            set link action bundle opt2
            set link disable multilink
            set link keep-alive 10 60
            set link max-redial 0
            set link disable chap pap
            set link accept chap pap eap
            set link disable incoming
            set link mtu 1492
            set auth authname "vodafone"
            set auth password vodafone
            set modem device /dev/cuaU0.0
            set modem script DialPeer
            set modem idle-script Ringback
            set modem watch -cd
            set modem var $DialPrefix "DT"
            set modem var $Telephone "*99#"
            set modem var $APN "live.vodafone.com"
            set modem var $APNum "1"
            open
    
    




  • Please read this post about the MPD binary.
    Maybe some files are outdated?
    http://sourceforge.net/projects/mpd/forums/forum/44693/topic/4516341



  • This affects the new Huawei e398 LTE modem as well.

    Relevant line reads:

    ppp: [wan] can't config [1c]:: Invalid argument
    


  • OK, Problem solved!!

    See http://sourceforge.net/projects/mpd/forums/forum/44693/topic/4516341

    Changed NG_PPP_MAX_BANDWIDTH in ng_ppp.h kernel file to a much higer value. The big BPS number of the K4505 Huawei modem is confusing the bandwidth maximum.

    
    /* Max allowable link latency (miliseconds) and bandwidth (bytes/second/10) */
    #define NG_PPP_MAX_LATENCY      1000            /* 1 second */
    #define NG_PPP_MAX_BANDWIDTH    125000          /* 10 Mbits / second */
    
    

    a MPD developer is changing the source of MPD5 now, so maybe update PFsense with the new MPD code in the future??



  • Imported the fix done on mpd5 sources in pfSense.



  • Does the Huawei E398 work with RC3 or what's the status? I'm having some trouble getting go grips with if it works or not. Some people are having trouble with usb_modeswitch and for some other it works.

    Could someone enlighten me?



  • @josege:

    Does the Huawei E398 work with RC3 or what's the status? I'm having some trouble getting go grips with if it works or not. Some people are having trouble with usb_modeswitch and for some other it works.

    Could someone enlighten me?

    The e398 works with the RC3. I use it on a laptop based home router an it serves well. (Thanks to ermal for the commit and GrandmasterB for the info). You may have to set it to 4G only on a Win PC first as I am uncertain if Linux and FreeBSD can set that parameter or how it will behave if set to auto.

    The only issues I encounter in experimenting occur - or so I think  for now - if other USB interfaces are activated. In my setup a reboot with an USB ethernet adapter and wireless adapter alongside the e398 - all with previously successfully assigned interfaces - saw an "interface mismatch" message and the interface assignment routine started. Removing and replacing the devices in some or other sequence saw the old assignments be picked up and the bootup completed. My impression is this is a usb-modeswitch issue with the e398 but more needs to be done to isolate what triggers it.


Log in to reply