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=0ls /dev/cua* reports the following available ports:
cuaU0.0, cuaU0.1, cuaU0.2, cuaU0.3, cuau0, cuau1There 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 terminateddmesg:
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 terminatedEverything 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 eventAnyone 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 -linkcreate 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"
openI 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 -
This user is also having the same problem:
http://forum.pfsense.org/index.php?action=profile;u=37021;sa=showPosts -
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?
-
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.