USB PPP 4G interface eventually goes down

Started by HappyDoer, September 02, 2024, 03:00:14 AM

Previous topic - Next topic
I've had this issue for as long as I can remember running opnsense (quite a few years now) and an outage this morning has meant I'm finally writing this post. I have a backup usb 4g modem (Sierra Wireless AirCard 320U) on Vodafone here in AU and connected to a PC Engines APU 2 running OPNsense 24.7.3_1-amd64.

Immediately after reboot the interface will come up and will be functional for what seems to be a random amount of time, usually a number of a days. It will then go down (i.e. the interface no longer has an address) and I haven't figured out a way to bring it back up short of rebooting, which works.

I've tried disabling the interface and enabling again, as well as saving the PPP settings again. Can anyone suggest how I can manually or automatically bring it back up, or get to the bottom of why it goes down in the first place? Not many settings involved, I believe it's only the following modified from defaults:


Interfaces: [PPP0]
Identifier: opt1
Device: ppp0
IPv4 Configuration Type: PPP
IPv6 Configuration Type: DHCPv6

PPP configuration
Modem Port: /dev/cuaU0.2
Phone Number: *99#
Access Point Name (APN): live.vodafone.com


I've also never had IPv6 get an address assigned either, though I don't think that's related. Appreciate any pointers.

Maybe the USB device just disconnects? Run usbconfig and check the system logs?

Quote from: HappyDoer on September 02, 2024, 03:00:14 AM
I've also never had IPv6 get an address assigned either, though I don't think that's related. Appreciate any pointers.

Maybe just set it to "None" then. This randomly found howto for some random VF gear suggests the APN should be vfinternet.au (Step 15).

Quote from: doktornotor on September 02, 2024, 04:02:05 AM
Maybe the USB device just disconnects? Run usbconfig and check the system logs?

Thanks, and that was information I should have included sorry - I have tried disconnecting the device and connecting it again after it loses IP assignment. usbconfig output for the device while it is up now looks like this:


ugen0.2: <Sierra Wireless, Incorporated AirCard 320U> at usbus0, cfg=0 md=HOST spd=HIGH (480Mbps) pwr=ON (500mA)


I'll compare after it goes down again. I've never seen anything relevant in the system logs each time I've checked unfortunately. Is there anywhere better than the "general" log files view to narrow logs to a specific interface?

Quote from: doktornotor on September 02, 2024, 04:02:05 AM
Maybe just set it to "None" then.

Yes, I could set it to none, though I mentioned it more because ideally ipv6 would work too but I have no idea where to start troubleshooting that either.

Quote from: doktornotor on September 02, 2024, 04:02:05 AM
This randomly found howto for some random VF gear suggests the APN should be vfinternet.au (Step 15).

I believe I tried the various APNs including vfinternet.au and came to the conclusion the one I'm using was correct; it may have even been the only that worked. I could test again, but the fact the connection is stable for days after boot makes me think it's unlikely to have any impact.

Quote from: HappyDoer on September 02, 2024, 04:46:13 AM
Yes, I could set it to none, though I mentioned it more because ideally ipv6 would work too but I have no idea where to start troubleshooting that either.

Has no influence on disconnects probably. Different APNs may have different results, some being IPv4 only, some have public IPs while some stick you behind CGNAT. IPv6 may require a special APN and can influence IPv4 as well. You need to check with VF.

Quote from: doktornotor on September 02, 2024, 04:57:08 AM
Has no influence on disconnects probably. Different APNs may have different results, some being IPv4 only, some have public IPs while some stick you behind CGNAT. IPv6 may require a special APN and can influence IPv4 as well. You need to check with VF.

Definitely have the correct APN. Just happened to me again, understand I need to be watching /var/log/ppps/latest.log. When it stops responding:


<30>1 2024-09-02T05:55:32+00:00 hostname ppp 62108 - [meta sequenceId="1"] [opt1_link0] MODEM: can't ioctl(TIOCMGET) /dev/cuaU0.2: Device not confi
gured
<30>1 2024-09-02T05:55:32+00:00 hostname ppp 62108 - [meta sequenceId="1"] [opt1_link0] MODEM: can't ioctl(TIOCMGET) /dev/cuaU0.2: Device not confi
gured
<30>1 2024-09-02T05:55:32+00:00 hostname ppp 62108 - [meta sequenceId="2"] [opt1_link0] Link: DOWN event
<30>1 2024-09-02T05:55:32+00:00 hostname ppp 62108 - [meta sequenceId="3"] [opt1_link0] LCP: Down event
<30>1 2024-09-02T05:55:32+00:00 hostname ppp 62108 - [meta sequenceId="4"] [opt1_link0] LCP: state change Opened --> Starting
<30>1 2024-09-02T05:55:32+00:00 hostname ppp 62108 - [meta sequenceId="5"] [opt1_link0] Link: Leave bundle "opt1"
<30>1 2024-09-02T05:55:32+00:00 hostname ppp 62108 - [meta sequenceId="6"] [opt1] Bundle: Status update: up 0 links, total bandwidth 9600 bps
<30>1 2024-09-02T05:55:32+00:00 hostname ppp 62108 - [meta sequenceId="7"] [opt1] IPCP: Close event
<30>1 2024-09-02T05:55:32+00:00 hostname ppp 62108 - [meta sequenceId="8"] [opt1] IPCP: state change Opened --> Closing
<30>1 2024-09-02T05:55:32+00:00 hostname ppp 62108 - [meta sequenceId="9"] [opt1] IPCP: SendTerminateReq #4
<30>1 2024-09-02T05:55:32+00:00 hostname ppp 62108 - [meta sequenceId="10"] [opt1] IPCP: LayerDown
<13>1 2024-09-02T05:55:32+00:00 hostname ppp 31425 - [meta sequenceId="11"] ppp-linkdown: executing on ppp0 for inet
<30>1 2024-09-02T05:55:33+00:00 hostname ppp 62108 - [meta sequenceId="12"] [opt1] IFACE: Down event
<30>1 2024-09-02T05:55:33+00:00 hostname ppp 62108 - [meta sequenceId="13"] [opt1] IFACE: Rename interface ppp0 to ppp0
<30>1 2024-09-02T05:55:33+00:00 hostname ppp 62108 - [meta sequenceId="14"] [opt1] IPV6CP: Close event
<30>1 2024-09-02T05:55:33+00:00 hostname ppp 62108 - [meta sequenceId="15"] [opt1] IPV6CP: state change Stopped --> Closed
<30>1 2024-09-02T05:55:33+00:00 hostname ppp 62108 - [meta sequenceId="16"] [opt1] IPCP: Down event
<30>1 2024-09-02T05:55:33+00:00 hostname ppp 62108 - [meta sequenceId="17"] [opt1] IPCP: LayerFinish
<30>1 2024-09-02T05:55:33+00:00 hostname ppp 62108 - [meta sequenceId="18"] [opt1] Bundle: No NCPs left. Closing links...
<30>1 2024-09-02T05:55:33+00:00 hostname ppp 62108 - [meta sequenceId="19"] [opt1] IPCP: state change Closing --> Initial
<30>1 2024-09-02T05:55:33+00:00 hostname ppp 62108 - [meta sequenceId="20"] [opt1] IPV6CP: Down event
<30>1 2024-09-02T05:55:33+00:00 hostname ppp 62108 - [meta sequenceId="21"] [opt1] IPV6CP: state change Closed --> Initial
<30>1 2024-09-02T05:55:33+00:00 hostname ppp 62108 - [meta sequenceId="22"] [opt1_link0] LCP: LayerDown
<30>1 2024-09-02T05:55:33+00:00 hostname ppp 62108 - [meta sequenceId="23"] [opt1_link0] Link: reconnection attempt 1 in 2 seconds


Then  connection failure attempts repeated indefinitely:


<30>1 2024-09-02T07:36:30+00:00 hostname ppp 88658 - [meta sequenceId="8560"] [opt1_link0] MODEM: chat script failed
<30>1 2024-09-02T07:36:30+00:00 hostname ppp 88658 - [meta sequenceId="8561"] [opt1_link0] Link: DOWN event
<30>1 2024-09-02T07:36:30+00:00 hostname ppp 88658 - [meta sequenceId="8562"] [opt1_link0] LCP: Down event
<30>1 2024-09-02T07:36:30+00:00 hostname ppp 88658 - [meta sequenceId="8563"] [opt1_link0] Link: reconnection attempt 2 in 4 seconds
<30>1 2024-09-02T07:36:34+00:00 hostname ppp 88658 - [meta sequenceId="8564"] [opt1_link0] Link: reconnection attempt 2
<30>1 2024-09-02T07:36:35+00:00 hostname ppp 88658 - [meta sequenceId="8565"] [opt1_link0] CHAT: The modem is not responding to "AT" at MomCmd: labeell.


Once again, after a reboot it comes up fine:


<30>1 2024-09-02T07:38:08+00:00 hostname ppp 6350 - [meta sequenceId="1"] Multi-link PPP daemon for FreeBSD
<30>1 2024-09-02T07:38:08+00:00 hostname ppp 6350 - [meta sequenceId="2"]
<30>1 2024-09-02T07:38:08+00:00 hostname ppp 6350 - [meta sequenceId="3"] process 6350 started, version 5.9
<30>1 2024-09-02T07:38:08+00:00 hostname ppp 6350 - [meta sequenceId="4"] web: web is not running
<30>1 2024-09-02T07:38:08+00:00 hostname ppp 6350 - [meta sequenceId="5"] [opt1] Bundle: Interface ng0 created
<30>1 2024-09-02T07:38:08+00:00 hostname ppp 6350 - [meta sequenceId="6"] [opt1_link0] Link: OPEN event
<30>1 2024-09-02T07:38:08+00:00 hostname ppp 6350 - [meta sequenceId="7"] [opt1_link0] LCP: Open event
<30>1 2024-09-02T07:38:08+00:00 hostname ppp 6350 - [meta sequenceId="8"] [opt1_link0] LCP: state change Initial --> Starting
<30>1 2024-09-02T07:38:08+00:00 hostname ppp 6350 - [meta sequenceId="9"] [opt1_link0] LCP: LayerStart
<30>1 2024-09-02T07:38:09+00:00 hostname ppp 6350 - [meta sequenceId="10"] [opt1_link0] CHAT: +CGDCONT=1,"IP","live.vodafone.com"
<30>1 2024-09-02T07:38:09+00:00 hostname ppp 6350 - [meta sequenceId="11"] [opt1_link0] CHAT: Detected Custom modem.
<30>1 2024-09-02T07:38:09+00:00 hostname ppp 6350 - [meta sequenceId="12"] [opt1_link0] CHAT: Dialing server at *99#...
<30>1 2024-09-02T07:38:09+00:00 hostname ppp 6350 - [meta sequenceId="13"] [opt1_link0] CHAT: ATDT*99#
<30>1 2024-09-02T07:38:09+00:00 hostname ppp 6350 - [meta sequenceId="14"] [opt1_link0] CHAT: Connected at 100000000.
<30>1 2024-09-02T07:38:09+00:00 hostname ppp 6350 - [meta sequenceId="15"] [opt1_link0] MODEM: chat script succeeded
<30>1 2024-09-02T07:38:09+00:00 hostname ppp 6350 - [meta sequenceId="16"] [opt1_link0] Link: UP event
<30>1 2024-09-02T07:38:09+00:00 hostname ppp 6350 - [meta sequenceId="17"] [opt1_link0] LCP: Up event
...


Wish I knew how to reinitialize the device like happens at boot so that it could be brought up again. I see plenty of similar issues being discussed with freebsd generally though so understand this is likely nothing directly related to opnsense.

September 02, 2024, 10:38:33 AM #5 Last Edit: September 02, 2024, 10:42:02 AM by doktornotor
Seems that - as I guessed above - the USB device simply disconnects from the OS.


[opt1_link0] MODEM: can't ioctl(TIOCMGET) /dev/cuaU0.2: Device not configured


If you do


ls -l /dev/cuaU0.2


at that time, probably not there any more, definitely not in a usable state.

Couldn't quickly find the equivalent FreeBSD manpage, but does not matter much.https://linux.die.net/man/4/tty_ioctl


TIOCMGET

int *argp
get the status of modem bits.


I do not think USB itself is a factor nor is it the APN.  I am also encountering the same problem and also with Australia Telstra 4G.  I have a Sierra Wireless MC7304 installed in a z4 Qotom motherboard so I would think that rules out a USB related problem. But yea I am having the same symptoms, works fine after a reboot sometimes even a few days then just stops working.  Seems I am able to jumpstart it back again by going to the ppp configuration in point-to-point and clicking the Save button.  But this workaround only works a few times and then just stops working altogether until I reboot again.  This workaround is still initiated manually which not practical.  I am also looking for something to automatically get it back up after it fails, maybe a script or cron job but need to find out what is actually happening during boot up that enables the 4G to connect without issues and replicate the actions to a script and automate when it goes down.


Taking into account the workaround provided by pva on the freebsd forum post, It may be as simple as creating a custom Monit script for OPNsense for when the interface goes down then "usbconfig reset" command is executed and then the ppp will establish the connection again on it's reconnection attempts.  Will do some testing and let you know if it works out.