* Re: Unsalble cellular connection [not found] <CAOf5uw=2U6MkcKP8OzWNyzwvxjAvYLdXuDASFVEjnWvMQ0fjHw@mail.gmail.com> @ 2019-08-19 1:51 ` JH 2019-08-19 5:38 ` Jonas Bonn 0 siblings, 1 reply; 28+ messages in thread From: JH @ 2019-08-19 1:51 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 1624 bytes --] Hi Michael, On 8/18/19, Michael Nazzareno Trimarchi <michael@amarulasolutions.com> wrote: > Aug 17 11:32:44 solar kernel: usb 1-1: new high-speed USB device > number 5 using ci_hdrc > Aug 17 11:32:45 solar kernel: usb 1-1: New USB device found, > idVendor=05c6, idProduct=90b2, bcdDevice= 0.00 > Aug 17 11:32:45 solar kernel: usb 1-1: New USB device strings: Mfr=1, > Product=2, SerialNumber=3 > Aug 17 11:32:45 solar kernel: usb 1-1: Product: QHSUSB__BULK > Aug 17 11:32:45 solar kernel: usb 1-1: Manufacturer: Qualcomm CDMA > Technologies MSM > Aug 17 11:32:45 solar kernel: usb 1-1: SerialNumber: 5ff10299 > > Here seems that reboot in bootloader mode. I have couple of disconnect > and reconnect and I don't know if connman > send some power on/off at command and make this strange behavior. The > fact that start in bootloader mode can be a power > issue? can you try to connect using a powered HUB? I did a couple of restarting ofonod and connmand during the debug, one or two times power recycling manually, not clear if it was me to cause those reboot or not. Like Daniel said, it was unlikely that connman would run reboot, it might just record some messages from kernel. Just talked to the hardware engineer, he said who is very concerning we are using kernel 5.1.0, he said we should use kernel 4.9.123, could the kernel 5.1.0 cause that issue? Jonas what is your comments? Let me further clarify it, the issue did not occur very often, it occurred randomly between hours to many days, that is a big worry, LTE should be 100% stable. Thank you. Kind regards, - jh ^ permalink raw reply [flat|nested] 28+ messages in thread
* Re: Unsalble cellular connection 2019-08-19 1:51 ` Unsalble cellular connection JH @ 2019-08-19 5:38 ` Jonas Bonn 2019-08-19 14:18 ` JH 0 siblings, 1 reply; 28+ messages in thread From: Jonas Bonn @ 2019-08-19 5:38 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 6697 bytes --] Hi JH, On 19/08/2019 03:51, JH wrote: > Hi Michael, > > On 8/18/19, Michael Nazzareno Trimarchi <michael@amarulasolutions.com> wrote: >> Aug 17 11:32:44 solar kernel: usb 1-1: new high-speed USB device >> number 5 using ci_hdrc >> Aug 17 11:32:45 solar kernel: usb 1-1: New USB device found, >> idVendor=05c6, idProduct=90b2, bcdDevice= 0.00 >> Aug 17 11:32:45 solar kernel: usb 1-1: New USB device strings: Mfr=1, >> Product=2, SerialNumber=3 >> Aug 17 11:32:45 solar kernel: usb 1-1: Product: QHSUSB__BULK >> Aug 17 11:32:45 solar kernel: usb 1-1: Manufacturer: Qualcomm CDMA >> Technologies MSM >> Aug 17 11:32:45 solar kernel: usb 1-1: SerialNumber: 5ff10299 >> >> Here seems that reboot in bootloader mode. I have couple of disconnect >> and reconnect and I don't know if connman >> send some power on/off at command and make this strange behavior. The >> fact that start in bootloader mode can be a power >> issue? can you try to connect using a powered HUB? > > I did a couple of restarting ofonod and connmand during the debug, one > or two times power recycling manually, not clear if it was me to cause > those reboot or not. > > Like Daniel said, it was unlikely that connman would run reboot, it > might just record some messages from kernel. Neither connman nor ofono are currently capable of rebooting the modem. > > Just talked to the hardware engineer, he said who is very concerning > we are using kernel 5.1.0, he said we should use kernel 4.9.123, could > the kernel 5.1.0 cause that issue? Jonas what is your comments? I find the advice rather concerning! Hope you're not getting investment advice from this guy, too... The kernel log has this: Aug 17 08:51:46 solar kernel: usb 1-1: USB disconnect, device number 3 Aug 17 08:51:46 solar kernel: option1 ttyUSB0: GSM modem (1-port) converter now disconnected from ttyUSB0 Aug 17 08:51:46 solar kernel: option 1-1:1.0: device disconnected Aug 17 08:51:46 solar kernel: option1 ttyUSB1: GSM modem (1-port) converter now disconnected from ttyUSB1 Aug 17 08:51:46 solar kernel: option 1-1:1.2: device disconnected Aug 17 08:51:46 solar kernel: qmi_wwan 1-1:1.3: nonzero urb status received: -71 That's a USB communication failure! Aug 17 08:51:46 solar kernel: qmi_wwan 1-1:1.3: wdm_int_callback - 0 bytes Aug 17 08:51:46 solar kernel: qmi_wwan 1-1:1.3: wdm_int_callback - usb_submit_urb failed with result -19 Aug 17 08:51:46 solar kernel: qmi_wwan 1-1:1.3 wwan0: unregister 'qmi_wwan' usb-ci_hdrc.1-1, WWAN/QMI device Below, the device (modem) is reenumerated, which would indicate to me that it has restarted. I don't think the kernel automatically sends a reset to a device on comm failures...??? This explains the communication failure, at least. Aug 17 08:51:49 solar kernel: usb 1-1: new high-speed USB device number 4 using ci_hdrc Aug 17 08:51:50 solar kernel: usb 1-1: New USB device found, idVendor=05c6, idProduct=90b2, bcdDevice= 0.00 Aug 17 08:51:50 solar kernel: usb 1-1: New USB device strings: Mfr=3, Product=2, SerialNumber=4 Aug 17 08:51:50 solar kernel: usb 1-1: Product: Qualcomm CDMA Technologies MSM Aug 17 08:51:50 solar kernel: usb 1-1: Manufacturer: Qualcomm, Incorporated Aug 17 08:51:50 solar kernel: usb 1-1: SerialNumber: 5ff10299 Aug 17 08:51:50 solar kernel: option 1-1:1.0: GSM modem (1-port) converter detected Aug 17 08:51:50 solar kernel: usb 1-1: GSM modem (1-port) converter now attached to ttyUSB0 Aug 17 08:51:50 solar kernel: option 1-1:1.2: GSM modem (1-port) converter detected Aug 17 08:51:50 solar kernel: usb 1-1: GSM modem (1-port) converter now attached to ttyUSB1 Aug 17 08:51:50 solar kernel: qmi_wwan 1-1:1.3: cdc-wdm0: USB WDM device Aug 17 08:51:50 solar kernel: qmi_wwan 1-1:1.3 wwan0: register 'qmi_wwan' at usb-ci_hdrc.1-1, WWAN/QMI device, f6:0d:90:fa:af:24 ofono should _definitely_ show this device reenumeration in its logs. Why is that not there??? ----------------------- Subsequently, the kernel log shows: Aug 17 11:32:43 solar kernel: usb 1-1: USB disconnect, device number 4 Aug 17 11:32:43 solar kernel: option1 ttyUSB0: GSM modem (1-port) converter now disconnected from ttyUSB0 Aug 17 11:32:43 solar kernel: option 1-1:1.0: device disconnected Aug 17 11:32:43 solar kernel: option1 ttyUSB1: GSM modem (1-port) converter now disconnected from ttyUSB1 Aug 17 11:32:43 solar kernel: option 1-1:1.2: device disconnected Aug 17 11:32:44 solar kernel: qmi_wwan 1-1:1.3: nonzero urb status received: -71 Again, comm error. Aug 17 11:32:44 solar kernel: qmi_wwan 1-1:1.3: wdm_int_callback - 0 bytes Aug 17 11:32:44 solar kernel: qmi_wwan 1-1:1.3: wdm_int_callback - usb_submit_urb failed with result -19 Aug 17 11:32:44 solar kernel: qmi_wwan 1-1:1.3 wwan0: unregister 'qmi_wwan' usb-ci_hdrc.1-1, WWAN/QMI device Modem has rebooted and is reenumerated below. Aug 17 11:32:44 solar kernel: usb 1-1: new high-speed USB device number 5 using ci_hdrc Aug 17 11:32:45 solar kernel: usb 1-1: New USB device found, idVendor=05c6, idProduct=90b2, bcdDevice= 0.00 Aug 17 11:32:45 solar kernel: usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Aug 17 11:32:45 solar kernel: usb 1-1: Product: QHSUSB__BULK Aug 17 11:32:45 solar kernel: usb 1-1: Manufacturer: Qualcomm CDMA Technologies MSM Aug 17 11:32:45 solar kernel: usb 1-1: SerialNumber: 5ff10299 Aug 17 11:32:45 solar kernel: option 1-1:1.0: GSM modem (1-port) converter detected Aug 17 11:32:45 solar kernel: usb 1-1: GSM modem (1-port) converter now attached to ttyUSB0 Here, however, the modem isn't booting up into normal operational state, but rather into some other configuration that, presumably, is intended for doing device firmware updates... So you have a couple of things to figure out: i) Why is the modem restarting (crashing) spontaneously? ii) What are the conditions for entering the bootloader/firmware update state? How are you managing to meet these conditions? iii) Why is ofono not showing the device reenumeration... it should, and it should show the modem being taken down and brought back up again. (I suspect it's just a matter of your logs being out of sync... it's probably there if you look, again). > > Let me further clarify it, the issue did not occur very often, it > occurred randomly between hours to many days, that is a big worry, LTE > should be 100% stable. The issue doesn't seem to have anything to do with the radio link. The LTE is probably stable; the issue lies elsewhere. /Jonas > > Thank you. > > Kind regards, > > - jh > ^ permalink raw reply [flat|nested] 28+ messages in thread
* Re: Unsalble cellular connection 2019-08-19 5:38 ` Jonas Bonn @ 2019-08-19 14:18 ` JH 0 siblings, 0 replies; 28+ messages in thread From: JH @ 2019-08-19 14:18 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 5877 bytes --] Hi Jonas, Let me clean up a little bit to take your notes and to answer your questions. On 8/19/19, Jonas Bonn <jonas@norrbonn.se> wrote: > Aug 17 08:51:46 solar kernel: usb 1-1: USB disconnect, device number 3 > Aug 17 08:51:46 solar kernel: option1 ttyUSB0: GSM modem (1-port) > converter now disconnected from ttyUSB0 > Aug 17 08:51:46 solar kernel: option 1-1:1.0: device disconnected > Aug 17 08:51:46 solar kernel: option1 ttyUSB1: GSM modem (1-port) > converter now disconnected from ttyUSB1 > Aug 17 08:51:46 solar kernel: option 1-1:1.2: device disconnected > Aug 17 08:51:46 solar kernel: qmi_wwan 1-1:1.3: nonzero urb status > received: -71 > > That's a USB communication failure! Did you referred to urb status -71 which is protocol error? Are there any chance that USB communication failure could be caused by kernel, connman or ofono? I guess the answer will be no. Is it correct that QMI driver is from ofono? What QMI version is it? > Aug 17 08:51:46 solar kernel: qmi_wwan 1-1:1.3: wdm_int_callback - 0 bytes > Aug 17 08:51:46 solar kernel: qmi_wwan 1-1:1.3: wdm_int_callback - > usb_submit_urb failed with result -19 > Aug 17 08:51:46 solar kernel: qmi_wwan 1-1:1.3 wwan0: unregister > 'qmi_wwan' usb-ci_hdrc.1-1, WWAN/QMI device > > Below, the device (modem) is reenumerated, which would indicate to me > that it has restarted. I don't think the kernel automatically sends a > reset to a device on comm failures...??? This explains the > communication failure, at least. It might me to run power up signal when the link was down. My question is, does the kernel knows how to restart the modem? The modem has a dedicated POWER_UP line in GPIO I can send echo command to turn the power up during the boot, according to the hardware engineer you can also send signal to turn the power down. My power up command is in a shell script which I make sure it will never put a wrong value to it. So two possibility, (1) something triggered modem power off; (2) something made modem crashed. It is unlikely that the kernel, ofono or connman can turn the modem power off, but any chance that kernel, ofono or connman could make the modem crash? > Again, comm error. Again I guess you referred to -71. > Aug 17 11:32:44 solar kernel: qmi_wwan 1-1:1.3: wdm_int_callback - 0 bytes > Aug 17 11:32:44 solar kernel: qmi_wwan 1-1:1.3: wdm_int_callback - > usb_submit_urb failed with result -19 > Aug 17 11:32:44 solar kernel: qmi_wwan 1-1:1.3 wwan0: unregister > 'qmi_wwan' usb-ci_hdrc.1-1, WWAN/QMI device > > Modem has rebooted and is reenumerated below. > > Aug 17 11:32:44 solar kernel: usb 1-1: new high-speed USB device number > 5 using ci_hdrc > Aug 17 11:32:45 solar kernel: usb 1-1: New USB device found, > idVendor=05c6, idProduct=90b2, bcdDevice= 0.00 > Aug 17 11:32:45 solar kernel: usb 1-1: New USB device strings: Mfr=1, > Product=2, SerialNumber=3 > Aug 17 11:32:45 solar kernel: usb 1-1: Product: QHSUSB__BULK > Aug 17 11:32:45 solar kernel: usb 1-1: Manufacturer: Qualcomm CDMA > Technologies MSM > Aug 17 11:32:45 solar kernel: usb 1-1: SerialNumber: 5ff10299 > Aug 17 11:32:45 solar kernel: option 1-1:1.0: GSM modem (1-port) > converter detected > Aug 17 11:32:45 solar kernel: usb 1-1: GSM modem (1-port) converter now > attached to ttyUSB0 > > Here, however, the modem isn't booting up into normal operational state, > but rather into some other configuration that, presumably, is intended > for doing device firmware updates... > So you have a couple of things to figure out: > i) Why is the modem restarting (crashing) spontaneously? Did you refer that usb_submit_urb failed with result -19 was crashed from init callback? > ii) What are the conditions for entering the bootloader/firmware update > state? How are you managing to meet these conditions? The SARA modem should never enter the bootloader / firmware update state unless you run the AT to manually update it. I'll check it with uBlox support. > iii) Why is ofono not showing the device reenumeration... it should, > and it should show the modem being taken down and brought back up again. > (I suspect it's just a matter of your logs being out of sync... it's > probably there if you look, again). I guess it was logs out of sync, I'll try it again. >> >> Let me further clarify it, the issue did not occur very often, it >> occurred randomly between hours to many days, that is a big worry, LTE >> should be 100% stable. > > The issue doesn't seem to have anything to do with the radio link. The > LTE is probably stable; the issue lies elsewhere. So your assert is something triggered modem power down or crash which brought the link down? I suggested the hardware engineer that power supply might not be stable to trigger the modem power down or crash, he totally denied it, He said, the same power supply for wifi and imx6 as well, if the power supply is the problem, wifi and imx6 would have problems as well. > Is the problem reproducible with the EVK? If not, you've pretty much eliminated software as > the cause of the issue... it's the same device, but with an independent power supply. I have never seen the problem running on EVK, but I could not run uncovered EVK in 24/7 for the safety reason, I might be able to find another device without integrated power supply and uses an external power supply, I'll test on that device in 24/7. > In JH's case, only the 'qmimisc' device and the 'network' interface are in play via ofono. > These are separate endpoints on a single USB interface, all managed by the qmi-wwan driver > in the kernel. So the kernel managed the USB interface and qmi-wwan driver, can the kernel cause the problem to crash USB or qmi driver? Thanks Jonas, I will found something to debug. - jh ^ permalink raw reply [flat|nested] 28+ messages in thread
[parent not found: <CAOf5uw=fQe4cuTfdciqW3hmXHXv-tY2UYd4aLfMVxF5Lx65jbw@mail.gmail.com>]
* Re: Unsalble cellular connection [not found] <CAOf5uw=fQe4cuTfdciqW3hmXHXv-tY2UYd4aLfMVxF5Lx65jbw@mail.gmail.com> @ 2019-08-19 8:17 ` Jonas Bonn 0 siblings, 0 replies; 28+ messages in thread From: Jonas Bonn @ 2019-08-19 8:17 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 1424 bytes --] Hi Michael, Re-adding JH and mailing lists to conversation... On 19/08/2019 10:00, Michael Nazzareno Trimarchi wrote: > Hi > > On Mon, Aug 19, 2019 at 9:51 AM Jonas Bonn <jonas@norrbonn.se> wrote: >> >> >> >> On 19/08/2019 09:36, Michael Nazzareno Trimarchi wrote: >>> Can be chattering and rush current? Even are you sure that you don't have >>> some reset our of the ofono service that send an at command that >>> restart the modem? >> >> Just to try to prevent us from going down the wrong rabbit hole here: >> i) The modem is a QMI device so there are no AT commands being sent > > Ok, so the uart used as ttyUSB0 and ttyUSB1 they don't support any AT command? > Is qmi part only the network interface? ttyUSB0 and ttyUSB1 _do_ support AT commands, but are complementary to the QMI interface which is a complete communication channel to the modem in itself. The network interface is _only_ for the QMI channel: the network packets are carried on a dedicated endpoint of the USB interface supporting QMI. I think the question of QMI vs AT is moot here. Internally the modem does pretty much the same thing; it's just the interface that looks a bit different. In JH's case, only the 'qmimisc' device and the 'network' interface are in play via ofono. These are separate endpoints on a single USB interface, all managed by the qmi-wwan driver in the kernel. /Jonas ^ permalink raw reply [flat|nested] 28+ messages in thread
[parent not found: <CAOf5uw=6hQkfhAt=OWH+mim30NyOHU6Z8GVMJ6yKCEf=1NFw8w@mail.gmail.com>]
* Re: Unsalble cellular connection [not found] <CAOf5uw=6hQkfhAt=OWH+mim30NyOHU6Z8GVMJ6yKCEf=1NFw8w@mail.gmail.com> @ 2019-08-19 7:50 ` Jonas Bonn 2019-08-19 7:56 ` Jonas Bonn 0 siblings, 1 reply; 28+ messages in thread From: Jonas Bonn @ 2019-08-19 7:50 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 6463 bytes --] On 19/08/2019 09:36, Michael Nazzareno Trimarchi wrote: > Hi > > On Mon, Aug 19, 2019 at 7:38 AM Jonas Bonn <jonas@norrbonn.se> wrote: >> The kernel log has this: >> >> Aug 17 08:51:46 solar kernel: usb 1-1: USB disconnect, device number 3 >> Aug 17 08:51:46 solar kernel: option1 ttyUSB0: GSM modem (1-port) >> converter now disconnected from ttyUSB0 >> Aug 17 08:51:46 solar kernel: option 1-1:1.0: device disconnected >> Aug 17 08:51:46 solar kernel: option1 ttyUSB1: GSM modem (1-port) >> converter now disconnected from ttyUSB1 >> Aug 17 08:51:46 solar kernel: option 1-1:1.2: device disconnected >> Aug 17 08:51:46 solar kernel: qmi_wwan 1-1:1.3: nonzero urb status >> received: -71 >> >> That's a USB communication failure! >> >> Aug 17 08:51:46 solar kernel: qmi_wwan 1-1:1.3: wdm_int_callback - 0 bytes >> Aug 17 08:51:46 solar kernel: qmi_wwan 1-1:1.3: wdm_int_callback - >> usb_submit_urb failed with result -19 >> Aug 17 08:51:46 solar kernel: qmi_wwan 1-1:1.3 wwan0: unregister >> 'qmi_wwan' usb-ci_hdrc.1-1, WWAN/QMI device >> >> Below, the device (modem) is reenumerated, which would indicate to me >> that it has restarted. I don't think the kernel automatically sends a >> reset to a device on comm failures...??? This explains the >> communication failure, at least. > > Can be chattering and rush current? Even are you sure that you don't have > some reset our of the ofono service that send an at command that > restart the modem? Just to try to prevent us from going down the wrong rabbit hole here: i) The modem is a QMI device so there are no AT commands being sent ii) The ofono log should show any such command if it were being transmitted (unfortunately, JH hasn't been able to produce a proper log around this event, yet) iii) I'm pretty certain that the QMI (gobi) driver in ofono doesn't support any 'reset' command My inclination would be to look elsewhere. i) figure out what reset signalling the modem does and put a scope on it. ii) try to eliminate ofono and connman from the picture entirely by running the modem manually... what's the utility called, qmictl? comes with libqmi, in any case. Presumably, if it's a hardware issue, the problem will show itself under these circumstances, as well. /Jonas > > Michael > >> >> Aug 17 08:51:49 solar kernel: usb 1-1: new high-speed USB device number >> 4 using ci_hdrc >> Aug 17 08:51:50 solar kernel: usb 1-1: New USB device found, >> idVendor=05c6, idProduct=90b2, bcdDevice= 0.00 >> Aug 17 08:51:50 solar kernel: usb 1-1: New USB device strings: Mfr=3, >> Product=2, SerialNumber=4 >> Aug 17 08:51:50 solar kernel: usb 1-1: Product: Qualcomm CDMA >> Technologies MSM >> Aug 17 08:51:50 solar kernel: usb 1-1: Manufacturer: Qualcomm, Incorporated >> Aug 17 08:51:50 solar kernel: usb 1-1: SerialNumber: 5ff10299 >> Aug 17 08:51:50 solar kernel: option 1-1:1.0: GSM modem (1-port) >> converter detected >> Aug 17 08:51:50 solar kernel: usb 1-1: GSM modem (1-port) converter now >> attached to ttyUSB0 >> Aug 17 08:51:50 solar kernel: option 1-1:1.2: GSM modem (1-port) >> converter detected >> Aug 17 08:51:50 solar kernel: usb 1-1: GSM modem (1-port) converter now >> attached to ttyUSB1 >> Aug 17 08:51:50 solar kernel: qmi_wwan 1-1:1.3: cdc-wdm0: USB WDM device >> Aug 17 08:51:50 solar kernel: qmi_wwan 1-1:1.3 wwan0: register >> 'qmi_wwan' at usb-ci_hdrc.1-1, WWAN/QMI device, f6:0d:90:fa:af:24 >> >> ofono should _definitely_ show this device reenumeration in its logs. >> Why is that not there??? >> >> ----------------------- >> >> Subsequently, the kernel log shows: >> >> Aug 17 11:32:43 solar kernel: usb 1-1: USB disconnect, device number 4 >> Aug 17 11:32:43 solar kernel: option1 ttyUSB0: GSM modem (1-port) >> converter now disconnected from ttyUSB0 >> Aug 17 11:32:43 solar kernel: option 1-1:1.0: device disconnected >> Aug 17 11:32:43 solar kernel: option1 ttyUSB1: GSM modem (1-port) >> converter now disconnected from ttyUSB1 >> Aug 17 11:32:43 solar kernel: option 1-1:1.2: device disconnected >> Aug 17 11:32:44 solar kernel: qmi_wwan 1-1:1.3: nonzero urb status >> received: -71 >> >> Again, comm error. >> >> Aug 17 11:32:44 solar kernel: qmi_wwan 1-1:1.3: wdm_int_callback - 0 bytes >> Aug 17 11:32:44 solar kernel: qmi_wwan 1-1:1.3: wdm_int_callback - >> usb_submit_urb failed with result -19 >> Aug 17 11:32:44 solar kernel: qmi_wwan 1-1:1.3 wwan0: unregister >> 'qmi_wwan' usb-ci_hdrc.1-1, WWAN/QMI device >> >> Modem has rebooted and is reenumerated below. >> >> Aug 17 11:32:44 solar kernel: usb 1-1: new high-speed USB device number >> 5 using ci_hdrc >> Aug 17 11:32:45 solar kernel: usb 1-1: New USB device found, >> idVendor=05c6, idProduct=90b2, bcdDevice= 0.00 >> Aug 17 11:32:45 solar kernel: usb 1-1: New USB device strings: Mfr=1, >> Product=2, SerialNumber=3 >> Aug 17 11:32:45 solar kernel: usb 1-1: Product: QHSUSB__BULK >> Aug 17 11:32:45 solar kernel: usb 1-1: Manufacturer: Qualcomm CDMA >> Technologies MSM >> Aug 17 11:32:45 solar kernel: usb 1-1: SerialNumber: 5ff10299 >> Aug 17 11:32:45 solar kernel: option 1-1:1.0: GSM modem (1-port) >> converter detected >> Aug 17 11:32:45 solar kernel: usb 1-1: GSM modem (1-port) converter now >> attached to ttyUSB0 >> >> Here, however, the modem isn't booting up into normal operational state, >> but rather into some other configuration that, presumably, is intended >> for doing device firmware updates... >> >> So you have a couple of things to figure out: >> i) Why is the modem restarting (crashing) spontaneously? >> ii) What are the conditions for entering the bootloader/firmware update >> state? How are you managing to meet these conditions? >> iii) Why is ofono not showing the device reenumeration... it should, >> and it should show the modem being taken down and brought back up again. >> (I suspect it's just a matter of your logs being out of sync... it's >> probably there if you look, again). >> >>> >>> Let me further clarify it, the issue did not occur very often, it >>> occurred randomly between hours to many days, that is a big worry, LTE >>> should be 100% stable. >> >> The issue doesn't seem to have anything to do with the radio link. The >> LTE is probably stable; the issue lies elsewhere. >> >> /Jonas >> >>> >>> Thank you. >>> >>> Kind regards, >>> >>> - jh >>> > > > ^ permalink raw reply [flat|nested] 28+ messages in thread
* Re: Unsalble cellular connection 2019-08-19 7:50 ` Jonas Bonn @ 2019-08-19 7:56 ` Jonas Bonn 0 siblings, 0 replies; 28+ messages in thread From: Jonas Bonn @ 2019-08-19 7:56 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 2628 bytes --] On 19/08/2019 09:50, Jonas Bonn wrote: > > > On 19/08/2019 09:36, Michael Nazzareno Trimarchi wrote: >> Hi >> >> On Mon, Aug 19, 2019 at 7:38 AM Jonas Bonn <jonas@norrbonn.se> wrote: >>> The kernel log has this: >>> >>> Aug 17 08:51:46 solar kernel: usb 1-1: USB disconnect, device number 3 >>> Aug 17 08:51:46 solar kernel: option1 ttyUSB0: GSM modem (1-port) >>> converter now disconnected from ttyUSB0 >>> Aug 17 08:51:46 solar kernel: option 1-1:1.0: device disconnected >>> Aug 17 08:51:46 solar kernel: option1 ttyUSB1: GSM modem (1-port) >>> converter now disconnected from ttyUSB1 >>> Aug 17 08:51:46 solar kernel: option 1-1:1.2: device disconnected >>> Aug 17 08:51:46 solar kernel: qmi_wwan 1-1:1.3: nonzero urb status >>> received: -71 >>> >>> That's a USB communication failure! >>> >>> Aug 17 08:51:46 solar kernel: qmi_wwan 1-1:1.3: wdm_int_callback - 0 >>> bytes >>> Aug 17 08:51:46 solar kernel: qmi_wwan 1-1:1.3: wdm_int_callback - >>> usb_submit_urb failed with result -19 >>> Aug 17 08:51:46 solar kernel: qmi_wwan 1-1:1.3 wwan0: unregister >>> 'qmi_wwan' usb-ci_hdrc.1-1, WWAN/QMI device >>> >>> Below, the device (modem) is reenumerated, which would indicate to me >>> that it has restarted. I don't think the kernel automatically sends a >>> reset to a device on comm failures...??? This explains the >>> communication failure, at least. >> >> Can be chattering and rush current? Even are you sure that you don't have >> some reset our of the ofono service that send an at command that >> restart the modem? > > Just to try to prevent us from going down the wrong rabbit hole here: > i) The modem is a QMI device so there are no AT commands being sent > ii) The ofono log should show any such command if it were being > transmitted (unfortunately, JH hasn't been able to produce a proper log > around this event, yet) > iii) I'm pretty certain that the QMI (gobi) driver in ofono doesn't > support any 'reset' command > > My inclination would be to look elsewhere. > > i) figure out what reset signalling the modem does and put a scope on it. > ii) try to eliminate ofono and connman from the picture entirely by > running the modem manually... what's the utility called, qmictl? comes > with libqmi, in any case. Presumably, if it's a hardware issue, the > problem will show itself under these circumstances, as well. > Is the problem reproducible with the EVK? If not, you've pretty much eliminated software as the cause of the issue... it's the same device, but with an independent power supply. /Jonas ^ permalink raw reply [flat|nested] 28+ messages in thread
[parent not found: <CAA=hcWSVcULFW4jo5q9RsxW4igozgM99oJN6KoZ8UaSLdLhD7g@mail.gmail.com>]
* Re: Unsalble cellular connection [not found] <CAA=hcWSVcULFW4jo5q9RsxW4igozgM99oJN6KoZ8UaSLdLhD7g@mail.gmail.com> @ 2019-08-13 15:00 ` Jonas Bonn 2019-08-14 11:11 ` JH 0 siblings, 1 reply; 28+ messages in thread From: Jonas Bonn @ 2019-08-13 15:00 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 10870 bytes --] CC: ofono mailing list. Please don't drop the mailing list from the conversation. On 13/08/2019 13:51, JH wrote: > Hi Jonas, > > On 8/13/19, Jonas Bonn <jonas@norrbonn.se> wrote: >> Hi JH, >>> Aug 01 08:09:39 connmand[181]: wwan0 {add} route 0.0.0.0 gw >>> 10.114.23.146 scope 0 <UNIVERSE> >>> Aug 01 08:09:45 connmand[181]: Online check failed for 0xa71cf8 Telstra > >> Online check failed... was the network connection ever working? > > Yes, it usually in good LTE connection when power up, then it dropped > connection in about 1 - 2 hours. > >>> Aug 01 09:34:11 connmand[181]: Time request for server 10.114.23.146 >>> failed (101/Network is unreachable) > >> Is this attempt to check the time server causing the modem to discover that the connection >> isn't working? Who sets the network interface DOWN here... the QMI Linux driver? Why >> doesn't the modem signal something on the QMI communication channel when this >> happens... maybe it does but the message is just being silently ignored? > > $ ping 10.114.23.146 > --- 10.114.23.146 ping statistics --- > 5 packets transmitted, 0 packets received, 100% packet loss > > Cannot reache that IP address?? That address is the gateway address for that link... there's unlikely a timeserver running there. Why does connman think there's a timeserver there? > >> There's very little traffic on the link... is the PDP context silently expiring due to inactivity? > > What happens if you ping something every minute or so when the link > is active? > > That because all traffic went to WiFi, the application is sending a > message to Cloud every minitue, should that be better than to ping? So you have no traffic over the LTE link? How do you know that it goes down after 1-2 hours... maybe it went down after 5 minutes? Cloud messages are as good as a ping... a packet's a packet. > >>> Aug 01 09:34:11 connmand[181]: wwan0 {del} address 10.114.23.145/30 label wwan0 >>> Aug 01 09:34:11 connmand[181]: Skipping disconnect of >>> /ubloxqmi_0/context1, network is connecting. > >> Here I think ofono and connman just get out of sync because connman seems to know that >> the network is down while ofono doesn't... > > Does that alude it is not the ofono caused link down? The link is configured by connman, not ofono. ofono just publishes the address details so that connman can set it up. > >> Sure... there's not much to go on in the logs you've posted, just an >> assertion that the LTE connection was silently dropped. It would be >> better if you could show the behaviour with more complete debug output: >> >> ofonod -d >> >> The issue could be (perhaps) that there's a QMI message that ofono >> doesn't handle and is silently ignoring... dumping the QMI communication >> might useful: >> >> OFONO_QMI_DEBUG=1 ofonod -d > > Before running following commands, the LTE connection dropped, after > running following commands, LTE connection came back, it is wired that > the LTE is more stable than running by system service where > ExecStart=/usr/sbin/ofonod -u", LTE connection has not been dropped > for more than 6 hours, I'll run it over night and let you know if the > connection will be dropped or not. Why running OFONO_QMI_DEBUG=1 > ofonod -d makes it more stable? Can I say that LTE drop off is caused > by the ofono? > > # systemctl stop ofono > # OFONO_QMI_DEBUG=1 ofonod -d > # ip addr > 1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue qlen 1000 > link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00 > inet 127.0.0.1/8 scope host lo > valid_lft forever preferred_lft forever > inet6 ::1/128 scope host > valid_lft forever preferred_lft forever > 2: sit0(a)NONE: <NOARP> mtu 1480 qdisc noop qlen 1000 > link/sit 0.0.0.0 brd 0.0.0.0 > 3: mlan0: <BROADCAST,MULTICAST,UP,LOWER_UP8000> mtu 1500 qdisc mq qlen 1000 > link/ether d4:ca:6e:64:e3:61 brd ff:ff:ff:ff:ff:ff > inet 192.168.0.101/24 brd 192.168.0.255 scope global mlan0 > valid_lft forever preferred_lft forever > inet6 fe80::d6ca:6eff:fe64:e361/64 scope link > valid_lft forever preferred_lft forever > 4: wwan0: <POINTOPOINT,MULTICAST,NOARP,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast q0 > link/[65534] > inet 10.114.34.107/29 brd 10.114.34.111 scope global wwan0 > valid_lft forever preferred_lft forever > > The LTE connection came up with IP address: > > wwan0 Link encap:UNSPEC HWaddr 00-00-00-00-00-00-00-00-00-00-00-00-00-00-0 > inet addr:10.114.34.107 P-t-P:10.114.34.107 Mask:255.255.255.248 > UP POINTOPOINT RUNNING NOARP MULTICAST MTU:1500 Metric:1 > RX packets:253 errors:0 dropped:0 overruns:0 frame:0 > TX packets:348 errors:0 dropped:0 overruns:0 carrier:0 > collisions:0 txqueuelen:1000 > RX bytes:28788 (28.1 KiB) TX bytes:37777 (36.8 KiB) > > > There is not much about the dump message: > > # journalctl -u ofono > -- Logs begin at Fri 2019-07-05 05:07:43 UTC, end at Tue 2019-08-13 09:15:10 UT- > Aug 11 12:07:12 systemd[1]: Starting Telephony service... > Aug 11 12:07:13 ofonod[189]: oFono version 1.24 > Aug 11 12:07:14 systemd[1]: Started Telephony service. > Aug 11 12:07:19 ofonod[189]: Interface org.ofono.AllowedAccessPoints not t > Aug 11 12:07:21 ofonod[189]: LTE attach IP type: 0 > Aug 12 06:30:19 ofonod[189]: LTE attach IP type: 0 > Aug 12 06:32:24 ofonod[189]: LTE attach IP type: 0 > Aug 12 06:33:28 ofonod[189]: LTE attach IP type: 0 > Aug 12 06:56:03 ofonod[189]: LTE attach IP type: 0 > Aug 12 06:56:06 ofonod[189]: LTE attach IP type: 0 > Aug 12 06:56:10 ofonod[189]: LTE attach IP type: 0 > Aug 13 08:49:09 ofonod[189]: Terminating > Aug 13 08:49:09 systemd[1]: Stopping Telephony service... > Aug 13 08:49:09 ofonod[189]: Exit > Aug 13 08:49:09 systemd[1]: Stopped Telephony service. > Aug 13 08:56:22 systemd[1]: Starting Telephony service... > Aug 13 08:56:22 ofonod[3315]: oFono version 1.24 > Aug 13 08:56:22 ofonod[3315]: Unable to hop onto D-Bus: Name already in ue > Aug 13 08:56:22 ofonod[3315]: Exit > Aug 13 08:56:22 systemd[1]: Started Telephony service. > Aug 13 08:57:29 systemd[1]: /lib/systemd/system/ofono.service:8: Executab" > Aug 13 09:00:30 systemd[1]: Starting Telephony service... > Aug 13 09:00:30 systemd[1]: Started Telephony service. > >>>> # ofono/test/list-contexts >>>> [ /ubloxqmi_0 ] >>>> [ /ubloxqmi_0/context1 ] >>>> Name = Internet >>>> Type = internet >>>> AuthenticationMethod = chap >>>> Settings = { Method=static Gateway=10.116.103.22 >>>> Netmask=255.255.255.25} >> >> No Address? No Interface? Running ofono with debug output will >> probably shed some light on what's going on here. > > I think that could be because I only ran it once, if I ran > list-contexts 4 times consecutively, every time it displayed different > results included address and interface, is it the normal behaviour of > list-contexts? Sounds broken...??? > > # /usr/lib/ofono/test/list-contexts > [ /ubloxqmi_0 ] > [ /ubloxqmi_0/context1 ] > AuthenticationMethod = chap > Active = 1 > Protocol = ip > Username = > Name = Internet > Type = internet > IPv6.Settings = { } > Password = > AccessPointName = telstra.m2m > Settings = { Gateway=10.114.34.108 Method=static > Interface=wwan0 Do UP POINTOPOINT RUNNING NOARP MULTICAST MTU:1500 > Metric:1 > RX packets:253 errors:0 dropped:0 overruns:0 frame:0 > TX packets:348 errors:0 dropped:0 overruns:0 carrier:0 > collisions:0 txqueuelen:1000 > RX bytes:28788 (28.1 KiB) TX bytes:37777 (36.8 KiB) > main} > > # /usr/lib/ofono/test/list-contexts > [ /ubloxqmi_0 ] > [ /ubloxqmi_0/context1 ] > AccessPointName = telstra.m2m > Protocol = ip > IPv6.Settings = { } > Active = 1 > Name = Internet > Type = internet > Settings = { Method=static Gateway=10.114.34.108 Netmask=255.255.255.24} > Password = > AuthenticationMethod = chap > Username = > > # /usr/lib/ofono/test/list-contexts > [ /ubloxqmi_0 ] > [ /ubloxqmi_0/context1 ] > Type = internet > AccessPointName = telstra.m2m > Settings = { Netmask=255.255.255.248 Interface=wwan0 Address=10.114.34.} > Name = Internet > Username = > Password = > Protocol = ip > Active = 1 > IPv6.Settings = { } > AuthenticationMethod = chap > >> static is correct. ofono configures the local network interface >> appropriately for the established context. >> >> Given that ofono isn't reporting either an address nor interface above, >> I wonder what the network interface has been configured to. What do 'ip >> link' and 'ip addr' show? > > Since it is running in good status, debug may not make sense, but I > include here anyway: > > # ip link > 1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue qlen 1000 > link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00 > 2: sit0(a)NONE: <NOARP> mtu 1480 qdisc noop qlen 1000 > link/sit 0.0.0.0 brd 0.0.0.0 > 3: mlan0: <BROADCAST,MULTICAST,UP,LOWER_UP8000> mtu 1500 qdisc mq qlen 1000 > link/ether d4:ca:6e:64:e3:61 brd ff:ff:ff:ff:ff:ff > 4: wwan0: <POINTOPOINT,MULTICAST,NOARP,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast q0 > link/[65534] > > # ip addr > 1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue qlen 1000 > link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00 > inet 127.0.0.1/8 scope host lo > valid_lft forever preferred_lft forever > inet6 ::1/128 scope host > valid_lft forever preferred_lft forever > 2: sit0(a)NONE: <NOARP> mtu 1480 qdisc noop qlen 1000 > link/sit 0.0.0.0 brd 0.0.0.0 > 3: mlan0: <BROADCAST,MULTICAST,UP,LOWER_UP8000> mtu 1500 qdisc mq qlen 1000 > link/ether d4:ca:6e:64:e3:61 brd ff:ff:ff:ff:ff:ff > inet 192.168.0.101/24 brd 192.168.0.255 scope global mlan0 > valid_lft forever preferred_lft forever > inet6 fe80::d6ca:6eff:fe64:e361/64 scope link > valid_lft forever preferred_lft forever > 4: wwan0: <POINTOPOINT,MULTICAST,NOARP,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast q0 > link/[65534] > inet 10.114.34.107/29 brd 10.114.34.111 scope global wwan0 > valid_lft forever preferred_lft forever > > I'll send you debug information when it is in bad connection status. > > Thank you all for you kind help. > > Kind regards, > > - jupiter > /Jonas ^ permalink raw reply [flat|nested] 28+ messages in thread
* Re: Unsalble cellular connection 2019-08-13 15:00 ` Jonas Bonn @ 2019-08-14 11:11 ` JH 2019-08-14 13:00 ` Jonas Bonn 0 siblings, 1 reply; 28+ messages in thread From: JH @ 2019-08-14 11:11 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 1741 bytes --] Hi Jonas, On 8/14/19, Jonas Bonn <jonas@norrbonn.se> wrote: > So you have no traffic over the LTE link? How do you know that it goes > down after 1-2 hours... maybe it went down after 5 minutes? I logged link status every 10 minutes. > Cloud messages are as good as a ping... a packet's a packet. > The link is configured by connman, not ofono. ofono just publishes the > address details so that connman can set it up. So, it is back to connman? >>> No Address? No Interface? Running ofono with debug output will >>> probably shed some light on what's going on here. >> >> I think that could be because I only ran it once, if I ran >> list-contexts 4 times consecutively, every time it displayed different >> results included address and interface, is it the normal behaviour of >> list-contexts? > > Sounds broken...??? Which one is broken, ofono or connman or something else? There is not much configurations for both ofono and connman, Can the defect hardware particularly the system power supply caused the link down? I have only one test device, I cannot prove it. The SATA chip has a pin for power up, During the boot, a command to set the power up before ofono is running. When the link is down, either I restart the ofonod or I called the command to turn the power up again, both can bring the link back. I cannot image the chip could lose power, but if the system power supply is not stable in some stage too low to support the SARA chip, will it trig the power down? I talked to the hardware engineer who rejected that it did not make sense because WiFi was running fine, he is pointing the figure to the modem manager and connection manager. Thank you. Kind regards, - jh ^ permalink raw reply [flat|nested] 28+ messages in thread
* Re: Unsalble cellular connection 2019-08-14 11:11 ` JH @ 2019-08-14 13:00 ` Jonas Bonn 2019-08-15 11:33 ` Daniel Wagner 2019-08-15 12:45 ` JH 0 siblings, 2 replies; 28+ messages in thread From: Jonas Bonn @ 2019-08-14 13:00 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 2841 bytes --] Hi JH, On 14/08/2019 13:11, JH wrote: > Hi Jonas, > > On 8/14/19, Jonas Bonn <jonas@norrbonn.se> wrote: >> So you have no traffic over the LTE link? How do you know that it goes >> down after 1-2 hours... maybe it went down after 5 minutes? > > I logged link status every 10 minutes. How? Not clear from what you posted earliest how you can tell that the link has gone down. The default route is set to go over WiFi so a generic ping isn't sufficient. What exactly are you monitoring? > >> Cloud messages are as good as a ping... a packet's a packet. >> The link is configured by connman, not ofono. ofono just publishes the >> address details so that connman can set it up. > > So, it is back to connman? Well, the log _seemed_ to indicate that connman does an NTP request to a server that isn't available and thereby decides to take the link down... off the top of my head I can't say whether that's something connman actually does so hopefully somebody else will jump in here. Did ofono indicate the context as still established after that? > >>>> No Address? No Interface? Running ofono with debug output will >>>> probably shed some light on what's going on here. >>> >>> I think that could be because I only ran it once, if I ran >>> list-contexts 4 times consecutively, every time it displayed different >>> results included address and interface, is it the normal behaviour of >>> list-contexts? >> >> Sounds broken...??? > > Which one is broken, ofono or connman or something else? There is not > much configurations for both ofono and connman, I was referring to the DBus response containing incomplete Settings objects. A random set of properties at each request is not the documented behaviour. > > Can the defect hardware particularly the system power supply caused > the link down? I have only one test device, I cannot prove it. The > SATA chip has a pin for power up, During the boot, a command to set > the power up before ofono is running. When the link is down, either I > restart the ofonod or I called the command to turn the power up again, > both can bring the link back. I cannot image the chip could lose > power, but if the system power supply is not stable in some stage too > low to support the SARA chip, will it trig the power down? I talked to > the hardware engineer who rejected that it did not make sense because > WiFi was running fine, he is pointing the figure to the modem manager > and connection manager. Seeing the issue with complete logs would be useful. I thought your previous logs indicated connman trying to deactivate the context when it took the link down, but the ofono logs didn't show any of that... what's going on there? /Jonas > > Thank you. > > Kind regards, > > - jh > ^ permalink raw reply [flat|nested] 28+ messages in thread
* Re: Unsalble cellular connection 2019-08-14 13:00 ` Jonas Bonn @ 2019-08-15 11:33 ` Daniel Wagner 2019-08-15 12:45 ` JH 1 sibling, 0 replies; 28+ messages in thread From: Daniel Wagner @ 2019-08-15 11:33 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 991 bytes --] Hi, On 8/14/19 3:00 PM, Jonas Bonn wrote: > Well, the log _seemed_ to indicate that connman does an NTP request to a > server that isn't available and thereby decides to take the link down... NTP lookup failures won't trigger a disconnect. As long oFono or the kernel via RNTL changes the state ConnMan doesn't change the routing. > off the top of my head I can't say whether that's something connman > actually does so hopefully somebody else will jump in here. Did ofono > indicate the context as still established after that? Mabye checking what monitor-ofono shows. > Seeing the issue with complete logs would be useful. I thought your > previous logs indicated connman trying to deactivate the context when it > took the link down, but the ofono logs didn't show any of that... what's > going on there? Yes, that is a good question. If oFono doesn't tell ConnMan anything, then ConnMan reacts to a state change of the device. Thanks, Daniel ^ permalink raw reply [flat|nested] 28+ messages in thread
* Re: Unsalble cellular connection 2019-08-14 13:00 ` Jonas Bonn 2019-08-15 11:33 ` Daniel Wagner @ 2019-08-15 12:45 ` JH 2019-08-15 14:58 ` Daniel Wagner 1 sibling, 1 reply; 28+ messages in thread From: JH @ 2019-08-15 12:45 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 2102 bytes --] Hi Jonas, On 8/14/19, Jonas Bonn <jonas@norrbonn.se> wrote: >> I logged link status every 10 minutes. > > How? Not clear from what you posted earliest how you can tell that the > link has gone down. The default route is set to go over WiFi so a > generic ping isn't sufficient. What exactly are you monitoring? I have a cron job to check LTE link IP, if the IP is gone that the link is down. I also connect the device and monitor it by serial port connection. I don't think that is important, let's move on. >> >>> Cloud messages are as good as a ping... a packet's a packet. >>> The link is configured by connman, not ofono. ofono just publishes the >>> address details so that connman can set it up. >> >> So, it is back to connman? > > Well, the log _seemed_ to indicate that connman does an NTP request to a > server that isn't available and thereby decides to take the link down... > off the top of my head I can't say whether that's something connman > actually does so hopefully somebody else will jump in here. Did ofono > indicate the context as still established after that? That seems critical, every time when the link down, connman called: connmand[213]: Time request for server 10.114.52.97 failed (101/Network is unreachable) Then deleted the link IP address to cause the link down: connmand[213]: wwan0 {del} address 10.114.52.98/30 label wwan0 connmand[213]: Skipping disconnect of /ubloxqmi_0/context1, network is connecting. connmand[213]: ipconfig state 2 ipconfig method 1 > Seeing the issue with complete logs would be useful. I thought your > previous logs indicated connman trying to deactivate the context when it > took the link down, but the ofono logs didn't show any of that... what's > going on there? The full connman log file attached, there was no information for ofono log files. I don't think that ofono was aware of that connman deleted the IP address from the LTE link, I cannot understand why the connman did it. Anyway, I'll try to debug and to generate ofono log again. Thank you Jonas, - jh [-- Warning: decoded text below may be mangled, UTF-8 assumed --] [-- Attachment #2: connman_bad.log --] [-- Type: text/x-log, Size: 80912 bytes --] -- Logs begin at Fri 2019-07-05 05:07:43 UTC, end at Sun 2019-08-11 11:33:55 UTC. -- Aug 10 12:43:08 solar systemd[1]: Starting Connection service... Aug 10 12:43:10 solar connmand[204]: Connection Manager version 1.35 Aug 10 12:43:10 solar connmand[204]: Adding configuration cellular Aug 10 12:43:10 solar connmand[204]: Adding service configuration cellular Aug 10 12:43:10 solar connmand[204]: Adding configuration wifi Aug 10 12:43:10 solar connmand[204]: Adding service configuration wifi Aug 10 12:43:10 solar connmand[204]: Checking loopback interface settings Aug 10 12:43:10 solar connmand[204]: System hostname is solar Aug 10 12:43:10 solar systemd[1]: Started Connection service. Aug 10 12:43:10 solar connmand[204]: lo {newlink} index 1 address 00:00:00:00:00:00 mtu 65536 Aug 10 12:43:10 solar connmand[204]: lo {newlink} index 1 operstate 0 <UNKNOWN> Aug 10 12:43:10 solar connmand[204]: sit0 {newlink} index 2 address 00:00:00:00:08:00 mtu 1480 Aug 10 12:43:10 solar connmand[204]: sit0 {newlink} index 2 operstate 2 <DOWN> Aug 10 12:43:10 solar connmand[204]: mlan0 {create} index 3 type 1 <ETHER> Aug 10 12:43:10 solar connmand[204]: mlan0 {update} flags 4098 <DOWN> Aug 10 12:43:10 solar connmand[204]: mlan0 {newlink} index 3 address D4:CA:6E:64:E3:B1 mtu 1500 Aug 10 12:43:10 solar connmand[204]: mlan0 {newlink} index 3 operstate 2 <DOWN> Aug 10 12:43:10 solar connmand[204]: Adding interface mlan0 [ wifi ] Aug 10 12:43:11 solar connmand[204]: mlan0 {update} flags 36931 <UP,RUNNING> Aug 10 12:43:11 solar connmand[204]: mlan0 {newlink} index 3 address D4:CA:6E:64:E3:B1 mtu 1500 Aug 10 12:43:11 solar connmand[204]: mlan0 {newlink} index 3 operstate 0 <UNKNOWN> Aug 10 12:43:11 solar connmand[204]: mlan0 {update} flags 36867 <UP> Aug 10 12:43:11 solar connmand[204]: mlan0 {newlink} index 3 address D4:CA:6E:64:E3:B1 mtu 1500 Aug 10 12:43:11 solar connmand[204]: mlan0 {newlink} index 3 operstate 2 <DOWN> Aug 10 12:43:11 solar connmand[204]: mlan0 {newlink} index 3 address D4:CA:6E:64:E3:B1 mtu 1500 Aug 10 12:43:11 solar connmand[204]: mlan0 {newlink} index 3 operstate 2 <DOWN> Aug 10 12:43:12 solar connmand[204]: Skipping disconnect of 4a757069746572496f54_managed_psk, network is connecting. Aug 10 12:43:12 solar connmand[204]: mlan0 {RX} 1 packets 113 bytes Aug 10 12:43:12 solar connmand[204]: mlan0 {TX} 0 packets 0 bytes Aug 10 12:43:12 solar connmand[204]: mlan0 {update} flags 102403 <UP,LOWER_UP> Aug 10 12:43:12 solar connmand[204]: mlan0 {newlink} index 3 address D4:CA:6E:64:E3:B1 mtu 1500 Aug 10 12:43:12 solar connmand[204]: mlan0 {newlink} index 3 operstate 5 <DORMANT> Aug 10 12:43:12 solar connmand[204]: mlan0 {add} route ff00:: gw :: scope 0 <UNIVERSE> Aug 10 12:43:12 solar connmand[204]: mlan0 {add} route fe80:: gw :: scope 0 <UNIVERSE> Aug 10 12:43:12 solar connmand[204]: mlan0 {RX} 2 packets 330 bytes Aug 10 12:43:12 solar connmand[204]: mlan0 {TX} 2 packets 248 bytes Aug 10 12:43:12 solar connmand[204]: mlan0 {update} flags 102467 <UP,RUNNING,LOWER_UP> Aug 10 12:43:12 solar connmand[204]: mlan0 {newlink} index 3 address D4:CA:6E:64:E3:B1 mtu 1500 Aug 10 12:43:12 solar connmand[204]: mlan0 {newlink} index 3 operstate 6 <UP> Aug 10 12:43:13 solar connmand[204]: wwan0 {create} index 4 type 1 <ETHER> Aug 10 12:43:13 solar connmand[204]: wwan0 {update} flags 4098 <DOWN> Aug 10 12:43:13 solar connmand[204]: wwan0 {newlink} index 4 address C2:2B:2B:31:5C:C6 mtu 1500 Aug 10 12:43:13 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 10 12:43:13 solar connmand[204]: Adding interface wwan0 [ cellular ] Aug 10 12:43:15 solar connmand[204]: mlan0 {add} address 192.168.0.102/24 label mlan0 family 2 Aug 10 12:43:15 solar connmand[204]: mlan0 {add} route 192.168.0.0 gw 0.0.0.0 scope 253 <LINK> Aug 10 12:43:15 solar connmand[204]: mlan0 {add} route 192.168.0.1 gw 0.0.0.0 scope 253 <LINK> Aug 10 12:43:15 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 10 12:43:15 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 10 12:43:16 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 10 12:43:16 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 10 12:43:16 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 10 12:43:16 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 10 12:43:16 solar connmand[204]: Skipping disconnect of /ubloxqmi_0/context1, network is connecting. Aug 10 12:43:16 solar connmand[204]: ipconfig state 2 ipconfig method 1 Aug 10 12:43:16 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 10 12:43:16 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 10 12:43:16 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 10 12:43:16 solar connmand[204]: wwan0 {add} route ff00:: gw :: scope 0 <UNIVERSE> Aug 10 12:43:16 solar connmand[204]: wwan0 {add} route fe80:: gw :: scope 0 <UNIVERSE> Aug 10 12:43:16 solar connmand[204]: rp_filter set to 2 (loose mode routing), old value was 1 Aug 10 12:43:17 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 10 12:43:17 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 10 12:43:17 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 10 12:43:17 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 10 12:43:17 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 10 12:43:17 solar connmand[204]: wwan0 {del} route fe80:: gw :: scope 0 <UNIVERSE> Aug 10 12:43:17 solar connmand[204]: wwan0 {del} route ff00:: gw :: scope 0 <UNIVERSE> Aug 10 12:43:17 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 10 12:43:18 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 10 12:43:18 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 10 12:43:18 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 10 12:43:18 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 10 12:43:19 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 02:45:36 solar connmand[204]: wwan0 {RX} 452 packets 48629 bytes Aug 11 02:45:36 solar connmand[204]: wwan0 {TX} 486 packets 77703 bytes Aug 11 02:45:36 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 02:45:36 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 02:45:36 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 02:45:36 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 02:45:36 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 02:45:36 solar connmand[204]: wwan0 {RX} 452 packets 48629 bytes Aug 11 02:45:36 solar connmand[204]: wwan0 {TX} 486 packets 77703 bytes Aug 11 02:45:36 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 02:45:36 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 02:45:36 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 02:45:37 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 02:45:37 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 02:45:37 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 02:45:37 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 02:45:37 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 02:45:37 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 02:45:37 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 02:45:37 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 02:45:37 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 02:45:37 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 02:45:37 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 02:45:37 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 02:45:38 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 02:45:38 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 02:45:38 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 02:45:38 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 02:45:39 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:29:56 solar connmand[204]: wwan0 {RX} 801 packets 82186 bytes Aug 11 05:29:56 solar connmand[204]: wwan0 {TX} 860 packets 136527 bytes Aug 11 05:29:56 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 05:29:56 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 05:29:56 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 05:29:56 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:29:56 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 05:29:56 solar connmand[204]: wwan0 {RX} 801 packets 82186 bytes Aug 11 05:29:56 solar connmand[204]: wwan0 {TX} 860 packets 136527 bytes Aug 11 05:29:56 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 05:29:56 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 05:29:56 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 05:29:56 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 05:29:56 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 05:29:56 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 05:29:56 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 05:29:56 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:29:56 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:29:56 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:29:56 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:29:56 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:29:57 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:29:57 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:29:57 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:29:57 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:29:57 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:29:57 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:29:57 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:29:58 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:46:26 solar connmand[204]: wwan0 {RX} 869 packets 91187 bytes Aug 11 05:46:26 solar connmand[204]: wwan0 {TX} 940 packets 148047 bytes Aug 11 05:46:26 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 05:46:26 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 05:46:26 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 05:46:26 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:46:26 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 05:46:26 solar connmand[204]: wwan0 {RX} 869 packets 91187 bytes Aug 11 05:46:26 solar connmand[204]: wwan0 {TX} 940 packets 148047 bytes Aug 11 05:46:26 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 05:46:26 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 05:46:26 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 05:46:26 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 05:46:26 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 05:46:26 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 05:46:26 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 05:46:26 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:46:26 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:46:26 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:46:26 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:46:26 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:46:27 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:46:27 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:46:27 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:46:27 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:46:27 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:46:27 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:46:27 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:46:28 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:54:43 solar connmand[204]: wwan0 {RX} 895 packets 93163 bytes Aug 11 05:54:43 solar connmand[204]: wwan0 {TX} 977 packets 151708 bytes Aug 11 05:54:43 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 05:54:43 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 05:54:43 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 05:54:43 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:54:43 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 05:54:43 solar connmand[204]: wwan0 {RX} 895 packets 93163 bytes Aug 11 05:54:43 solar connmand[204]: wwan0 {TX} 977 packets 151708 bytes Aug 11 05:54:43 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 05:54:43 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 05:54:43 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 05:54:43 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 05:54:43 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 05:54:43 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 05:54:43 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 05:54:43 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:54:43 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:54:43 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:54:43 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:54:43 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:54:44 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:54:44 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:54:44 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:54:44 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:54:44 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:54:44 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:54:44 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:54:45 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:55:44 solar connmand[204]: wwan0 {RX} 908 packets 94319 bytes Aug 11 05:55:44 solar connmand[204]: wwan0 {TX} 1000 packets 153647 bytes Aug 11 05:55:44 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 05:55:44 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 05:55:44 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 05:55:44 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:55:44 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 05:55:44 solar connmand[204]: wwan0 {RX} 908 packets 94319 bytes Aug 11 05:55:44 solar connmand[204]: wwan0 {TX} 1000 packets 153647 bytes Aug 11 05:55:44 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 05:55:44 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 05:55:44 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 05:55:44 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 05:55:44 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 05:55:44 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 05:55:44 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 05:55:44 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:55:44 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:55:44 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:55:44 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:55:44 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:55:44 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:55:44 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:55:44 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:55:45 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:55:45 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:55:45 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:55:45 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:55:46 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:55:46 solar connmand[204]: wwan0 {RX} 919 packets 95371 bytes Aug 11 05:55:46 solar connmand[204]: wwan0 {TX} 1019 packets 155061 bytes Aug 11 05:55:46 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 05:55:46 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 05:55:46 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 05:55:46 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:55:46 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 05:55:46 solar connmand[204]: wwan0 {RX} 919 packets 95371 bytes Aug 11 05:55:46 solar connmand[204]: wwan0 {TX} 1019 packets 155061 bytes Aug 11 05:55:46 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 05:55:46 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 05:55:46 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 05:55:46 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:55:46 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 05:55:46 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 05:55:46 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 05:55:46 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 05:55:46 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:55:46 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:55:46 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:55:46 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:55:47 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:55:47 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:55:47 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:55:47 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:55:47 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:55:47 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:55:48 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:55:49 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:56:45 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:56:45 solar connmand[204]: wwan0 {RX} 935 packets 96707 bytes Aug 11 05:56:45 solar connmand[204]: wwan0 {TX} 1046 packets 157247 bytes Aug 11 05:56:45 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 05:56:45 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 05:56:45 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 05:56:45 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:56:45 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 05:56:45 solar connmand[204]: wwan0 {RX} 935 packets 96707 bytes Aug 11 05:56:45 solar connmand[204]: wwan0 {TX} 1046 packets 157247 bytes Aug 11 05:56:45 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 05:56:45 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 05:56:45 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 05:56:45 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 05:56:46 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 05:56:46 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 05:56:46 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 05:56:46 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:56:46 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:56:46 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:56:46 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:56:46 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:56:46 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:56:46 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:56:46 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:56:47 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:56:47 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:56:47 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:56:47 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:56:48 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:59:53 solar connmand[204]: wwan0 {RX} 950 packets 97967 bytes Aug 11 05:59:53 solar connmand[204]: wwan0 {TX} 1071 packets 159399 bytes Aug 11 05:59:53 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 05:59:53 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 05:59:53 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 05:59:53 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:59:53 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 05:59:53 solar connmand[204]: wwan0 {RX} 950 packets 97967 bytes Aug 11 05:59:53 solar connmand[204]: wwan0 {TX} 1071 packets 159399 bytes Aug 11 05:59:53 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 05:59:53 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 05:59:53 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 05:59:53 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 05:59:53 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 05:59:53 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 05:59:53 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 05:59:53 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:59:53 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:59:53 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:59:53 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:59:54 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:59:54 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 05:59:54 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 05:59:59 solar connmand[204]: Online check failed for 0x574e30 Telstra Aug 11 06:32:17 solar connmand[204]: wwan0 {RX} 958 packets 98383 bytes Aug 11 06:32:17 solar connmand[204]: wwan0 {TX} 1076 packets 159765 bytes Aug 11 06:32:17 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 06:32:17 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 06:32:17 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 06:32:17 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 06:32:17 solar connmand[204]: wwan0 {RX} 958 packets 98383 bytes Aug 11 06:32:17 solar connmand[204]: wwan0 {TX} 1076 packets 159765 bytes Aug 11 06:32:17 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 06:32:17 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 06:32:17 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 06:32:17 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 06:32:17 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 06:32:17 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:32:17 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:32:17 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:17 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:19 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:19 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:19 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:19 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:20 solar connmand[204]: wwan0 {RX} 966 packets 99073 bytes Aug 11 06:32:20 solar connmand[204]: wwan0 {TX} 1090 packets 160847 bytes Aug 11 06:32:20 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 06:32:20 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 06:32:20 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 06:32:20 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:20 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 06:32:20 solar connmand[204]: wwan0 {RX} 966 packets 99073 bytes Aug 11 06:32:20 solar connmand[204]: wwan0 {TX} 1090 packets 160847 bytes Aug 11 06:32:20 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 06:32:20 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 06:32:20 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 06:32:20 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 06:32:20 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 06:32:20 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:32:20 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:32:20 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:20 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:20 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:20 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:21 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:21 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:21 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:21 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:22 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:22 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:22 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:22 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:23 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:28 solar connmand[204]: wwan0 {RX} 979 packets 100229 bytes Aug 11 06:32:28 solar connmand[204]: wwan0 {TX} 1112 packets 162453 bytes Aug 11 06:32:28 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 06:32:28 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 06:32:28 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 06:32:28 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:28 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 06:32:28 solar connmand[204]: wwan0 {RX} 979 packets 100229 bytes Aug 11 06:32:28 solar connmand[204]: wwan0 {TX} 1112 packets 162453 bytes Aug 11 06:32:28 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 06:32:28 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 06:32:28 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 06:32:28 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 06:32:28 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 06:32:28 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:32:28 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:32:28 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:29 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:29 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:29 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:29 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:29 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:29 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:29 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:30 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:30 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:30 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:30 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:31 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:31 solar connmand[204]: Time request for server 10.116.108.45 failed (101/Network is unreachable) Aug 11 06:32:31 solar connmand[204]: wwan0 {RX} 990 packets 101281 bytes Aug 11 06:32:31 solar connmand[204]: wwan0 {TX} 1131 packets 163867 bytes Aug 11 06:32:31 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 06:32:31 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 06:32:31 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 06:32:31 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:31 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 06:32:31 solar connmand[204]: wwan0 {RX} 991 packets 101333 bytes Aug 11 06:32:31 solar connmand[204]: wwan0 {TX} 1131 packets 163867 bytes Aug 11 06:32:31 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 06:32:31 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 06:32:31 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 06:32:31 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 06:32:31 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 06:32:31 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:32:31 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:32:31 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:31 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:31 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:31 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:31 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:32 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:32 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:32 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:32 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:32 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:32 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:33 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:34 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:35 solar connmand[204]: Time request for server 10.116.108.45 failed (101/Network is unreachable) Aug 11 06:32:35 solar connmand[204]: wwan0 {RX} 1004 packets 102477 bytes Aug 11 06:32:35 solar connmand[204]: wwan0 {TX} 1151 packets 165333 bytes Aug 11 06:32:35 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 06:32:35 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 06:32:35 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 06:32:35 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:35 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 06:32:35 solar connmand[204]: Skipping disconnect of /ubloxqmi_0/context1, network is connecting. Aug 11 06:32:35 solar connmand[204]: ipconfig state 2 ipconfig method 1 Aug 11 06:32:35 solar connmand[204]: wwan0 {RX} 1004 packets 102477 bytes Aug 11 06:32:35 solar connmand[204]: wwan0 {TX} 1151 packets 165333 bytes Aug 11 06:32:35 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 06:32:35 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 06:32:35 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 06:32:35 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:35 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 06:32:35 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 06:32:35 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:32:35 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:32:35 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:35 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:35 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:35 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:36 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:36 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:36 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:36 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:36 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:32:36 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:36 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:32:37 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:33:58 solar connmand[204]: wwan0 {RX} 1016 packets 103581 bytes Aug 11 06:33:58 solar connmand[204]: wwan0 {TX} 1180 packets 168165 bytes Aug 11 06:33:58 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 06:33:58 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 06:33:58 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 06:33:58 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:33:58 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 06:33:58 solar connmand[204]: wwan0 {RX} 1016 packets 103581 bytes Aug 11 06:33:58 solar connmand[204]: wwan0 {TX} 1180 packets 168165 bytes Aug 11 06:33:58 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 06:33:58 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 06:33:58 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 06:33:58 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 06:33:58 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 06:33:58 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:33:58 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:33:58 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:33:58 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:33:58 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:33:58 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:33:58 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:33:59 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:33:59 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:33:59 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:33:59 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:33:59 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:33:59 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:33:59 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:34:01 solar connmand[204]: wwan0 {RX} 1024 packets 104271 bytes Aug 11 06:34:01 solar connmand[204]: wwan0 {TX} 1196 packets 169399 bytes Aug 11 06:34:01 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 06:34:01 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 06:34:01 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 06:34:01 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:34:01 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 06:34:01 solar connmand[204]: wwan0 {RX} 1024 packets 104271 bytes Aug 11 06:34:01 solar connmand[204]: wwan0 {TX} 1196 packets 169399 bytes Aug 11 06:34:01 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 06:34:01 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 06:34:01 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 06:34:01 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:34:01 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 06:34:01 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 06:34:01 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:34:01 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:34:01 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:34:01 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:34:01 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:34:01 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:34:01 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:34:01 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:34:01 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:34:02 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:34:02 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:34:02 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:34:02 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:34:03 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:45:17 solar connmand[204]: wwan0 {RX} 1041 packets 105865 bytes Aug 11 06:45:17 solar connmand[204]: wwan0 {TX} 1228 packets 172293 bytes Aug 11 06:45:17 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 06:45:17 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 06:45:17 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 06:45:17 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:45:17 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 06:45:17 solar connmand[204]: wwan0 {RX} 1041 packets 105865 bytes Aug 11 06:45:17 solar connmand[204]: wwan0 {TX} 1228 packets 172293 bytes Aug 11 06:45:17 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 06:45:17 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 06:45:17 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 06:45:17 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 06:45:17 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 06:45:17 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:45:17 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:45:17 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:45:17 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:45:17 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:45:17 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:45:18 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:45:18 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:45:19 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:47:43 solar connmand[204]: wwan0 {RX} 1074 packets 111438 bytes Aug 11 06:47:43 solar connmand[204]: wwan0 {TX} 1267 packets 177697 bytes Aug 11 06:47:43 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 06:47:43 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 06:47:43 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 06:47:43 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:47:43 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 06:47:43 solar connmand[204]: wwan0 {RX} 1074 packets 111438 bytes Aug 11 06:47:43 solar connmand[204]: wwan0 {TX} 1267 packets 177697 bytes Aug 11 06:47:43 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 06:47:43 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 06:47:43 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 06:47:43 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 06:47:43 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 06:47:43 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:47:43 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:47:43 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:47:43 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:47:43 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:47:43 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:47:44 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:47:45 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:47:45 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:49:43 solar connmand[204]: wwan0 {RX} 1087 packets 115531 bytes Aug 11 06:49:43 solar connmand[204]: wwan0 {TX} 1288 packets 179501 bytes Aug 11 06:49:43 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 06:49:43 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 06:49:43 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 06:49:43 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:49:43 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 06:49:43 solar connmand[204]: wwan0 {RX} 1087 packets 115531 bytes Aug 11 06:49:43 solar connmand[204]: wwan0 {TX} 1288 packets 179501 bytes Aug 11 06:49:43 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 06:49:43 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 06:49:43 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 06:49:43 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 06:49:43 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 06:49:43 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:49:43 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:49:43 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:49:43 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:49:43 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:49:43 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:49:44 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:49:44 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:49:45 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:49:46 solar connmand[204]: Time request for server 10.116.108.45 failed (101/Network is unreachable) Aug 11 06:49:46 solar connmand[204]: wwan0 {RX} 1093 packets 116083 bytes Aug 11 06:49:46 solar connmand[204]: wwan0 {TX} 1298 packets 180246 bytes Aug 11 06:49:46 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 06:49:46 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 06:49:46 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 06:49:46 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:49:46 solar connmand[204]: wwan0 {RX} 1093 packets 116083 bytes Aug 11 06:49:46 solar connmand[204]: wwan0 {TX} 1298 packets 180246 bytes Aug 11 06:49:46 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 06:49:46 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 06:49:46 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 06:49:46 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:49:46 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 06:49:46 solar connmand[204]: wwan0 {del} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:49:46 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 06:49:46 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 06:49:46 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:49:46 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 06:49:46 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:49:46 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:49:46 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:49:46 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:49:46 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:49:47 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:49:47 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:49:47 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:49:47 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:49:47 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 06:49:47 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:49:47 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 06:49:49 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:42 solar connmand[204]: Time request for server 10.116.108.45 failed (101/Network is unreachable) Aug 11 07:08:42 solar connmand[204]: wwan0 {RX} 1137 packets 119187 bytes Aug 11 07:08:42 solar connmand[204]: wwan0 {TX} 1352 packets 186393 bytes Aug 11 07:08:42 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 07:08:42 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 07:08:42 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 07:08:42 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:08:42 solar connmand[204]: wwan0 {RX} 1137 packets 119187 bytes Aug 11 07:08:42 solar connmand[204]: wwan0 {TX} 1352 packets 186393 bytes Aug 11 07:08:42 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 07:08:42 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 07:08:42 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 07:08:42 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 07:08:42 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 07:08:42 solar connmand[204]: wwan0 {del} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 07:08:42 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 07:08:42 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 07:08:42 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 07:08:42 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 07:08:42 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:42 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:08:42 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:42 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:08:43 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:43 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:08:43 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:43 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:08:44 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:44 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:08:44 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:44 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:45 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:45 solar connmand[204]: wwan0 {RX} 1148 packets 120239 bytes Aug 11 07:08:45 solar connmand[204]: wwan0 {TX} 1372 packets 187883 bytes Aug 11 07:08:45 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 07:08:45 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 07:08:45 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 07:08:45 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:08:45 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 07:08:45 solar connmand[204]: wwan0 {RX} 1148 packets 120239 bytes Aug 11 07:08:45 solar connmand[204]: wwan0 {TX} 1372 packets 187883 bytes Aug 11 07:08:45 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 07:08:45 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 07:08:45 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 07:08:45 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:08:45 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 07:08:45 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 07:08:45 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 07:08:45 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 07:08:45 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:45 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:08:45 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:45 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:46 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:08:46 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:46 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:08:47 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:47 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:08:47 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:47 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:47 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:48 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:48 solar connmand[204]: wwan0 {RX} 1161 packets 121395 bytes Aug 11 07:08:48 solar connmand[204]: wwan0 {TX} 1394 packets 189489 bytes Aug 11 07:08:48 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 07:08:48 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 07:08:48 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 07:08:48 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:08:48 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 07:08:48 solar connmand[204]: wwan0 {RX} 1161 packets 121395 bytes Aug 11 07:08:48 solar connmand[204]: wwan0 {TX} 1394 packets 189489 bytes Aug 11 07:08:48 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 07:08:48 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 07:08:48 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 07:08:48 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:08:48 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 07:08:48 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 07:08:48 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 07:08:48 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 07:08:48 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:48 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:08:48 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:48 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:49 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:08:49 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:49 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:08:49 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:49 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:08:49 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:50 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:08:50 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:17:09 solar connmand[204]: wwan0 {RX} 1206 packets 126800 bytes Aug 11 07:17:09 solar connmand[204]: wwan0 {TX} 1455 packets 197318 bytes Aug 11 07:17:09 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 07:17:09 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 07:17:09 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 07:17:09 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:17:09 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 07:17:09 solar connmand[204]: wwan0 {RX} 1206 packets 126800 bytes Aug 11 07:17:09 solar connmand[204]: wwan0 {TX} 1455 packets 197318 bytes Aug 11 07:17:09 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 07:17:09 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 07:17:09 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 07:17:09 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 07:17:09 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 07:17:09 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 07:17:09 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 07:17:09 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:17:09 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:17:09 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:17:09 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:17:09 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:17:10 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:17:10 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:17:10 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:17:10 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:17:10 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:17:10 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:17:10 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:17:11 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:17:12 solar connmand[204]: wwan0 {RX} 1221 packets 128412 bytes Aug 11 07:17:12 solar connmand[204]: wwan0 {TX} 1478 packets 199072 bytes Aug 11 07:17:12 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 07:17:12 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 07:17:12 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 07:17:12 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:17:12 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 07:17:12 solar connmand[204]: wwan0 {RX} 1222 packets 128464 bytes Aug 11 07:17:12 solar connmand[204]: wwan0 {TX} 1478 packets 199072 bytes Aug 11 07:17:12 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 07:17:12 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 07:17:12 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 07:17:12 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:17:12 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 07:17:12 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 07:17:12 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 07:17:12 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 07:17:12 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:17:12 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:17:12 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:17:12 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:17:13 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:17:13 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:17:13 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:17:13 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:17:13 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:17:13 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:17:13 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:17:14 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:45:16 solar connmand[204]: wwan0 {RX} 1266 packets 131292 bytes Aug 11 07:45:16 solar connmand[204]: wwan0 {TX} 1533 packets 206612 bytes Aug 11 07:45:16 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 07:45:16 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 07:45:16 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 07:45:16 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:45:16 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 07:45:16 solar connmand[204]: wwan0 {RX} 1266 packets 131292 bytes Aug 11 07:45:16 solar connmand[204]: wwan0 {TX} 1533 packets 206612 bytes Aug 11 07:45:16 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 07:45:16 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 07:45:16 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 07:45:16 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 07:45:16 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 07:45:16 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 07:45:16 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 07:45:16 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:45:16 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:45:16 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:45:16 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:45:16 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:45:17 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:45:17 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:45:17 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:45:18 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:45:18 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:45:18 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:45:18 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:45:19 solar connmand[204]: wwan0 {RX} 1274 packets 131982 bytes Aug 11 07:45:19 solar connmand[204]: wwan0 {TX} 1549 packets 207846 bytes Aug 11 07:45:19 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 07:45:19 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 07:45:19 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 07:45:19 solar connmand[204]: Time request for server 10.116.108.45 failed (101/Network is unreachable) Aug 11 07:45:19 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:45:19 solar connmand[204]: wwan0 {RX} 1275 packets 132034 bytes Aug 11 07:45:19 solar connmand[204]: wwan0 {TX} 1549 packets 207846 bytes Aug 11 07:45:19 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 07:45:19 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 07:45:19 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 07:45:19 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 07:45:19 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 07:45:19 solar connmand[204]: wwan0 {del} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 07:45:19 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 07:45:19 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 07:45:19 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 07:45:19 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 07:45:19 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:45:19 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:45:19 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:45:19 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:45:19 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:45:20 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:45:20 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:45:20 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:45:20 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:45:20 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:45:20 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:45:21 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:45:21 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:48:21 solar connmand[204]: wwan0 {RX} 1319 packets 138613 bytes Aug 11 07:48:21 solar connmand[204]: wwan0 {TX} 1603 packets 214402 bytes Aug 11 07:48:21 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 07:48:21 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 07:48:21 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 07:48:21 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:48:21 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 07:48:21 solar connmand[204]: wwan0 {RX} 1319 packets 138613 bytes Aug 11 07:48:21 solar connmand[204]: wwan0 {TX} 1603 packets 214402 bytes Aug 11 07:48:21 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 07:48:21 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 07:48:21 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 07:48:21 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 07:48:21 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 07:48:22 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 07:48:22 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 07:48:22 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:48:22 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:48:22 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:48:22 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:48:22 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:48:22 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:48:22 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:48:22 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:48:23 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:48:23 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 07:48:23 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:48:23 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 07:48:24 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 08:01:42 solar connmand[204]: wwan0 {RX} 1351 packets 140949 bytes Aug 11 08:01:42 solar connmand[204]: wwan0 {TX} 1646 packets 219161 bytes Aug 11 08:01:42 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 08:01:42 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 08:01:42 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 08:01:42 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 08:01:42 solar connmand[204]: wwan0 {del} address 10.116.108.44/29 label wwan0 Aug 11 08:01:42 solar connmand[204]: wwan0 {RX} 1351 packets 140949 bytes Aug 11 08:01:42 solar connmand[204]: wwan0 {TX} 1646 packets 219161 bytes Aug 11 08:01:42 solar connmand[204]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> Aug 11 08:01:42 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 08:01:42 solar connmand[204]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> Aug 11 08:01:42 solar connmand[204]: ipconfig state 3 ipconfig method 1 Aug 11 08:01:42 solar connmand[204]: wwan0 {add} address 10.116.108.44/29 label wwan0 family 2 Aug 11 08:01:42 solar connmand[204]: wwan0 {add} route 10.116.108.40 gw 0.0.0.0 scope 253 <LINK> Aug 11 08:01:42 solar connmand[204]: wwan0 {add} route 10.116.108.45 gw 0.0.0.0 scope 253 <LINK> Aug 11 08:01:42 solar connmand[204]: wwan0 {add} route 10.4.27.70 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 08:01:42 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 08:01:42 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 08:01:42 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 08:01:43 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 08:01:43 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 08:01:43 solar connmand[204]: wwan0 {del} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 08:01:43 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 08:01:44 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 08:01:44 solar connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 08:01:44 solar connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 08:01:44 solar connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 08:01:45 solar connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 08:02:48 solar connmand[204]: wwan0 {RX} 1365 packets 142181 bytes Aug 11 08:02:49 solar connmand[204]: wwan0 {TX} 1672 packets 221297 bytes Aug 11 08:02:49 solar connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 08:02:49 solar connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 08:02:49 solar connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 08:02:49 solar connmand[204]: (null) {del} address 10.116.108.44/29 label wwan0 Aug 11 08:02:49 solar connmand[204]: wwan0 {dellink} index 4 operstate 2 <DOWN> Aug 11 08:02:49 solar connmand[204]: (null) {RX} 1365 packets 142181 bytes Aug 11 08:02:49 solar connmand[204]: (null) {TX} 1672 packets 221297 bytes Aug 11 08:02:49 solar connmand[204]: (null) {remove} index 4 Aug 11 08:02:49 solar connmand[204]: Remove interface (null) [ cellular ] Aug 11 08:02:49 solar connmand[204]: Removing default gateway route failed (No such device) Aug 11 08:02:49 solar connmand[204]: Deleting host route failed (No such device) Aug 11 08:02:49 solar connmand[204]: Deleting host route failed (No such device) Aug 11 08:02:49 solar connmand[204]: Removing default gateway route failed (No such device) Aug 11 08:02:49 solar connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 08:02:49 solar connmand[204]: Skipping disconnect of /ubloxqmi_0/context1, network is connecting. Aug 11 08:02:49 solar connmand[204]: ipconfig state 2 ipconfig method 1 Aug 11 08:02:49 solar connmand[204]: Deleting host route failed (No such device) Aug 11 08:02:49 solar connmand[204]: mlan0 {add} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 08:02:50 solar connmand[204]: mlan0 {del} route 212.227.81.55 gw 192.168.0.1 scope 0 <UNIVERSE> ^ permalink raw reply [flat|nested] 28+ messages in thread
* Re: Unsalble cellular connection 2019-08-15 12:45 ` JH @ 2019-08-15 14:58 ` Daniel Wagner 2019-08-17 11:53 ` JH 0 siblings, 1 reply; 28+ messages in thread From: Daniel Wagner @ 2019-08-15 14:58 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 1726 bytes --] On 8/15/19 2:45 PM, JH wrote: >> Well, the log _seemed_ to indicate that connman does an NTP request to a >> server that isn't available and thereby decides to take the link down... >> off the top of my head I can't say whether that's something connman >> actually does so hopefully somebody else will jump in here. Did ofono >> indicate the context as still established after that? > > That seems critical, every time when the link down, connman called: > > connmand[213]: Time request for server 10.114.52.97 failed > (101/Network is unreachable) The NTP code is just telling it can't reach the server. This has no direct connenction to the next entry. > Then deleted the link IP address to cause the link down: > connmand[213]: wwan0 {del} address 10.114.52.98/30 label wwan0 This message is from the kernel via RTNL interface. The kernel tells ConnMan the interface state has changed. > connmand[213]: Skipping disconnect of /ubloxqmi_0/context1, network is > connecting. > connmand[213]: ipconfig state 2 ipconfig method 1 and the above is then the cause of the RTNL message. >> Seeing the issue with complete logs would be useful. I thought your >> previous logs indicated connman trying to deactivate the context when it >> took the link down, but the ofono logs didn't show any of that... what's >> going on there? > > The full connman log file attached, there was no information for ofono > log files. I don't think that ofono was aware of that connman deleted > the IP address from the LTE link, I cannot understand why the connman > did it. Anyway, I'll try to debug and to generate ofono log again. Your log does not contain the debug information (connmand -d). ^ permalink raw reply [flat|nested] 28+ messages in thread
* Re: Unsalble cellular connection 2019-08-15 14:58 ` Daniel Wagner @ 2019-08-17 11:53 ` JH 2019-08-17 11:55 ` JH 0 siblings, 1 reply; 28+ messages in thread From: JH @ 2019-08-17 11:53 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 729 bytes --] On 8/16/19, Daniel Wagner <wagi@monom.org> wrote: > The NTP code is just telling it can't reach the server. This has no > direct connenction to the next entry. So that from NTP, don't need to worry about it. > This message is from the kernel via RTNL interface. The kernel tells > ConnMan the interface state has changed. OK, all from kernel, what could make the kernel to delete the link? >> connmand[213]: Skipping disconnect of /ubloxqmi_0/context1, network is >> connecting. >> connmand[213]: ipconfig state 2 ipconfig method 1 > Your log does not contain the debug information (connmand -d). I attached two log files running in debug, doesn't seem $ OFONO_QMI_DEBUG=1 ofonod -d $ connmand -d ^ permalink raw reply [flat|nested] 28+ messages in thread
* Re: Unsalble cellular connection 2019-08-17 11:53 ` JH @ 2019-08-17 11:55 ` JH 2019-08-17 14:09 ` Jonas Bonn 0 siblings, 1 reply; 28+ messages in thread From: JH @ 2019-08-17 11:55 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 942 bytes --] On 8/17/19, JH <jupiter.hce@gmail.com> wrote: > On 8/16/19, Daniel Wagner <wagi@monom.org> wrote: >> The NTP code is just telling it can't reach the server. This has no >> direct connenction to the next entry. > > So that from NTP, don't need to worry about it. > >> This message is from the kernel via RTNL interface. The kernel tells >> ConnMan the interface state has changed. > > OK, all from kernel, what could make the kernel to delete the link? > > >>> connmand[213]: Skipping disconnect of /ubloxqmi_0/context1, network is >>> connecting. >>> connmand[213]: ipconfig state 2 ipconfig method 1 > >> Your log does not contain the debug information (connmand -d). > > I attached two log files running in debug, doesn't seem > > $ OFONO_QMI_DEBUG=1 ofonod -d > > $ connmand -d Oops, pressed wrong key, both debug log files attached, looks even less information from running ofono -n and connman -n by systemd. [-- Warning: decoded text below may be mangled, UTF-8 assumed --] [-- Attachment #2: ofono.log --] [-- Type: text/x-log, Size: 3348 bytes --] -- Logs begin at Fri 2019-08-16 07:45:56 UTC, end at Sat 2019-08-17 11:33:03 UTC. -- Aug 16 07:46:08 systemd[1]: Starting Telephony service... Aug 16 07:46:09 ofonod[178]: oFono version 1.24 Aug 16 07:46:10 systemd[1]: Started Telephony service. Aug 16 07:46:16 ofonod[178]: Interface org.ofono.AllowedAccessPoints not found on the interface_list Aug 16 07:46:49 ofonod[178]: Interface org.ofono.AllowedAccessPoints not found on the interface_list Aug 16 07:52:28 ofonod[178]: Terminating Aug 16 07:52:28 systemd[1]: Stopping Telephony service... Aug 16 07:52:28 ofonod[178]: Exit Aug 16 07:52:28 systemd[1]: Stopped Telephony service. Aug 16 11:32:52 systemd[1]: Starting Telephony service... Aug 16 11:32:52 ofonod[395]: oFono version 1.24 Aug 16 11:32:52 ofonod[395]: Unable to hop onto D-Bus: Name already in use Aug 16 11:32:52 ofonod[395]: Exit Aug 16 11:32:52 systemd[1]: Started Telephony service. Aug 16 11:32:52 systemd[1]: Starting Telephony service... Aug 16 11:32:52 ofonod[402]: oFono version 1.24 Aug 16 11:32:52 ofonod[402]: Unable to hop onto D-Bus: Name already in use Aug 16 11:32:52 ofonod[402]: Exit Aug 16 11:32:52 systemd[1]: Started Telephony service. Aug 16 11:50:35 systemd[1]: Starting Telephony service... Aug 16 11:50:35 ofonod[661]: oFono version 1.24 Aug 16 11:50:35 ofonod[661]: Unable to hop onto D-Bus: Name already in use Aug 16 11:50:35 ofonod[661]: Exit Aug 16 11:50:35 systemd[1]: Started Telephony service. Aug 16 11:50:35 systemd[1]: Starting Telephony service... Aug 16 11:50:35 ofonod[664]: oFono version 1.24 Aug 16 11:50:35 ofonod[664]: Unable to hop onto D-Bus: Name already in use Aug 16 11:50:35 ofonod[664]: Exit Aug 16 11:50:35 systemd[1]: Started Telephony service. Aug 16 11:59:16 systemd[1]: Starting Telephony service... Aug 16 11:59:16 ofonod[743]: oFono version 1.24 Aug 16 11:59:16 ofonod[743]: Unable to hop onto D-Bus: Name already in use Aug 16 11:59:16 ofonod[743]: Exit Aug 16 11:59:16 systemd[1]: Started Telephony service. Aug 16 11:59:16 systemd[1]: Starting Telephony service... Aug 16 11:59:16 ofonod[749]: oFono version 1.24 Aug 16 11:59:16 ofonod[749]: Unable to hop onto D-Bus: Name already in use Aug 16 11:59:16 ofonod[749]: Exit Aug 16 11:59:16 systemd[1]: Started Telephony service. Aug 16 13:09:27 systemd[1]: Starting Telephony service... Aug 16 13:09:27 ofonod[1047]: oFono version 1.24 Aug 16 13:09:27 ofonod[1047]: Unable to hop onto D-Bus: Name already in use Aug 16 13:09:27 ofonod[1047]: Exit Aug 16 13:09:27 systemd[1]: Started Telephony service. Aug 16 13:09:27 systemd[1]: Starting Telephony service... Aug 16 13:09:28 ofonod[1051]: oFono version 1.24 Aug 16 13:09:28 ofonod[1051]: Unable to hop onto D-Bus: Name already in use Aug 16 13:09:28 ofonod[1051]: Exit Aug 16 13:09:28 systemd[1]: Started Telephony service. Aug 17 10:35:45 systemd[1]: Starting Telephony service... Aug 17 10:35:45 ofonod[3487]: oFono version 1.24 Aug 17 10:35:45 ofonod[3487]: Unable to hop onto D-Bus: Name already in use Aug 17 10:35:45 ofonod[3487]: Exit Aug 17 10:35:45 systemd[1]: Started Telephony service. Aug 17 10:35:46 systemd[1]: Starting Telephony service... Aug 17 10:35:46 ofonod[3491]: oFono version 1.24 Aug 17 10:35:46 ofonod[3491]: Unable to hop onto D-Bus: Name already in use Aug 17 10:35:46 ofonod[3491]: Exit Aug 17 10:35:46 systemd[1]: Started Telephony service. [-- Warning: decoded text below may be mangled, UTF-8 assumed --] [-- Attachment #3: connman.log --] [-- Type: text/x-log, Size: 17262 bytes --] -- Logs begin at Fri 2019-08-16 07:45:56 UTC, end at Sat 2019-08-17 11:33:03 UTC. -- Aug 16 07:46:07 systemd[1]: Starting Connection service... Aug 16 07:46:09 connmand[174]: Connection Manager version 1.35 Aug 16 07:46:10 systemd[1]: Started Connection service. Aug 16 07:46:10 connmand[174]: Adding configuration cellular Aug 16 07:46:10 connmand[174]: Checking loopback interface settings Aug 16 07:46:10 connmand[174]: System hostname is solar Aug 16 07:46:11 connmand[174]: lo {newlink} index 1 address 00:00:00:00:00:00 mtu 65536 Aug 16 07:46:11 connmand[174]: lo {newlink} index 1 operstate 0 <UNKNOWN> Aug 16 07:46:11 connmand[174]: sit0 {newlink} index 2 address 00:00:00:00:08:00 mtu 1480 Aug 16 07:46:11 connmand[174]: sit0 {newlink} index 2 operstate 2 <DOWN> Aug 16 07:46:12 connmand[174]: wwan0 {create} index 3 type 1 <ETHER> Aug 16 07:46:12 connmand[174]: wwan0 {update} flags 4098 <DOWN> Aug 16 07:46:12 connmand[174]: wwan0 {newlink} index 3 address F6:0D:90:FA:AF:24 mtu 1500 Aug 16 07:46:12 connmand[174]: wwan0 {newlink} index 3 operstate 2 <DOWN> Aug 16 07:46:12 connmand[174]: Adding interface wwan0 [ cellular ] Aug 16 07:46:17 connmand[174]: mlan0 {create} index 4 type 1 <ETHER> Aug 16 07:46:17 connmand[174]: mlan0 {update} flags 4098 <DOWN> Aug 16 07:46:17 connmand[174]: mlan0 {newlink} index 4 address D4:CA:6E:64:E3:61 mtu 1500 Aug 16 07:46:17 connmand[174]: mlan0 {newlink} index 4 operstate 2 <DOWN> Aug 16 07:46:17 connmand[174]: Adding interface mlan0 [ wifi ] Aug 16 07:46:44 connmand[174]: wwan0 {dellink} index 3 operstate 2 <DOWN> Aug 16 07:46:44 connmand[174]: (null) {remove} index 3 Aug 16 07:46:44 connmand[174]: Remove interface (null) [ cellular ] Aug 16 07:46:48 connmand[174]: wwan0 {create} index 5 type 1 <ETHER> Aug 16 07:46:48 connmand[174]: wwan0 {update} flags 4098 <DOWN> Aug 16 07:46:48 connmand[174]: wwan0 {newlink} index 5 address F6:0D:90:FA:AF:24 mtu 1500 Aug 16 07:46:48 connmand[174]: wwan0 {newlink} index 5 operstate 2 <DOWN> Aug 16 07:46:48 connmand[174]: Adding interface wwan0 [ cellular ] Aug 16 08:02:28 connmand[174]: Terminating Aug 16 08:02:28 systemd[1]: Stopping Connection service... Aug 16 08:02:28 connmand[174]: Remove interface mlan0 [ wifi ] Aug 16 08:02:28 connmand[174]: Remove interface wwan0 [ cellular ] Aug 16 08:02:28 connmand[174]: Removing configuration cellular Aug 16 08:02:28 systemd[1]: Stopped Connection service. Aug 16 08:02:28 connmand[174]: mlan0 {remove} index 4 Aug 16 08:02:28 connmand[174]: wwan0 {remove} index 5 Aug 16 08:02:28 connmand[174]: Exit Aug 16 11:32:52 systemd[1]: Starting Connection service... Aug 16 11:32:52 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 16 11:32:52 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 11:32:52 systemd[1]: Failed to start Connection service. Aug 16 11:32:52 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 16 11:32:52 systemd[1]: connman.service: Scheduled restart job, restart counter is at 1. Aug 16 11:32:52 systemd[1]: Stopped Connection service. Aug 16 11:32:52 systemd[1]: Starting Connection service... Aug 16 11:32:53 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 16 11:32:53 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 11:32:53 systemd[1]: Failed to start Connection service. Aug 16 11:32:53 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 16 11:32:53 systemd[1]: connman.service: Scheduled restart job, restart counter is at 2. Aug 16 11:32:53 systemd[1]: Stopped Connection service. Aug 16 11:32:53 systemd[1]: Starting Connection service... Aug 16 11:32:53 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 16 11:32:53 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 11:32:53 systemd[1]: Failed to start Connection service. Aug 16 11:32:53 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 16 11:32:53 systemd[1]: connman.service: Scheduled restart job, restart counter is at 3. Aug 16 11:32:53 systemd[1]: Stopped Connection service. Aug 16 11:32:53 systemd[1]: Starting Connection service... Aug 16 11:32:53 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 16 11:32:53 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 11:32:53 systemd[1]: Failed to start Connection service. Aug 16 11:32:54 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 16 11:32:54 systemd[1]: connman.service: Scheduled restart job, restart counter is at 4. Aug 16 11:32:54 systemd[1]: Stopped Connection service. Aug 16 11:32:54 systemd[1]: Starting Connection service... Aug 16 11:32:54 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 16 11:32:54 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 11:32:54 systemd[1]: Failed to start Connection service. Aug 16 11:32:54 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 16 11:32:54 systemd[1]: connman.service: Scheduled restart job, restart counter is at 5. Aug 16 11:32:54 systemd[1]: Stopped Connection service. Aug 16 11:32:54 systemd[1]: connman.service: Start request repeated too quickly. Aug 16 11:32:54 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 11:32:54 systemd[1]: Failed to start Connection service. Aug 16 11:50:35 systemd[1]: Starting Connection service... Aug 16 11:50:35 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 16 11:50:35 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 11:50:35 systemd[1]: Failed to start Connection service. Aug 16 11:50:35 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 16 11:50:35 systemd[1]: connman.service: Scheduled restart job, restart counter is at 1. Aug 16 11:50:35 systemd[1]: Stopped Connection service. Aug 16 11:50:35 systemd[1]: Starting Connection service... Aug 16 11:50:36 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 16 11:50:36 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 11:50:36 systemd[1]: Failed to start Connection service. Aug 16 11:50:36 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 16 11:50:36 systemd[1]: connman.service: Scheduled restart job, restart counter is at 2. Aug 16 11:50:36 systemd[1]: Stopped Connection service. Aug 16 11:50:36 systemd[1]: Starting Connection service... Aug 16 11:50:36 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 16 11:50:36 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 11:50:36 systemd[1]: Failed to start Connection service. Aug 16 11:50:36 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 16 11:50:36 systemd[1]: connman.service: Scheduled restart job, restart counter is at 3. Aug 16 11:50:36 systemd[1]: Stopped Connection service. Aug 16 11:50:36 systemd[1]: Starting Connection service... Aug 16 11:50:36 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 16 11:50:36 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 11:50:36 systemd[1]: Failed to start Connection service. Aug 16 11:50:37 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 16 11:50:37 systemd[1]: connman.service: Scheduled restart job, restart counter is at 4. Aug 16 11:50:37 systemd[1]: Stopped Connection service. Aug 16 11:50:37 systemd[1]: Starting Connection service... Aug 16 11:50:37 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 16 11:50:37 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 11:50:37 systemd[1]: Failed to start Connection service. Aug 16 11:50:37 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 16 11:50:37 systemd[1]: connman.service: Scheduled restart job, restart counter is at 5. Aug 16 11:50:37 systemd[1]: Stopped Connection service. Aug 16 11:50:37 systemd[1]: connman.service: Start request repeated too quickly. Aug 16 11:50:37 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 11:50:37 systemd[1]: Failed to start Connection service. Aug 16 11:59:16 systemd[1]: Starting Connection service... Aug 16 11:59:16 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 16 11:59:16 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 11:59:16 systemd[1]: Failed to start Connection service. Aug 16 11:59:16 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 16 11:59:16 systemd[1]: connman.service: Scheduled restart job, restart counter is at 1. Aug 16 11:59:16 systemd[1]: Stopped Connection service. Aug 16 11:59:16 systemd[1]: Starting Connection service... Aug 16 11:59:17 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 16 11:59:17 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 11:59:17 systemd[1]: Failed to start Connection service. Aug 16 11:59:17 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 16 11:59:17 systemd[1]: connman.service: Scheduled restart job, restart counter is at 2. Aug 16 11:59:17 systemd[1]: Stopped Connection service. Aug 16 11:59:17 systemd[1]: Starting Connection service... Aug 16 11:59:17 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 16 11:59:17 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 11:59:17 systemd[1]: Failed to start Connection service. Aug 16 11:59:17 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 16 11:59:17 systemd[1]: connman.service: Scheduled restart job, restart counter is at 3. Aug 16 11:59:17 systemd[1]: Stopped Connection service. Aug 16 11:59:17 systemd[1]: Starting Connection service... Aug 16 11:59:17 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 16 11:59:17 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 11:59:17 systemd[1]: Failed to start Connection service. Aug 16 11:59:18 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 16 11:59:18 systemd[1]: connman.service: Scheduled restart job, restart counter is at 4. Aug 16 11:59:18 systemd[1]: Stopped Connection service. Aug 16 11:59:18 systemd[1]: Starting Connection service... Aug 16 11:59:18 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 16 11:59:18 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 11:59:18 systemd[1]: Failed to start Connection service. Aug 16 11:59:18 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 16 11:59:18 systemd[1]: connman.service: Scheduled restart job, restart counter is at 5. Aug 16 11:59:18 systemd[1]: Stopped Connection service. Aug 16 11:59:18 systemd[1]: connman.service: Start request repeated too quickly. Aug 16 11:59:18 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 11:59:18 systemd[1]: Failed to start Connection service. Aug 16 13:09:27 systemd[1]: Starting Connection service... Aug 16 13:09:27 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 16 13:09:27 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 13:09:27 systemd[1]: Failed to start Connection service. Aug 16 13:09:27 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 16 13:09:27 systemd[1]: connman.service: Scheduled restart job, restart counter is at 1. Aug 16 13:09:28 systemd[1]: Stopped Connection service. Aug 16 13:09:28 systemd[1]: Starting Connection service... Aug 16 13:09:28 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 16 13:09:28 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 13:09:28 systemd[1]: Failed to start Connection service. Aug 16 13:09:28 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 16 13:09:28 systemd[1]: connman.service: Scheduled restart job, restart counter is at 2. Aug 16 13:09:28 systemd[1]: Stopped Connection service. Aug 16 13:09:28 systemd[1]: Starting Connection service... Aug 16 13:09:28 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 16 13:09:28 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 13:09:28 systemd[1]: Failed to start Connection service. Aug 16 13:09:29 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 16 13:09:29 systemd[1]: connman.service: Scheduled restart job, restart counter is at 3. Aug 16 13:09:29 systemd[1]: Stopped Connection service. Aug 16 13:09:29 systemd[1]: Starting Connection service... Aug 16 13:09:29 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 16 13:09:29 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 13:09:29 systemd[1]: Failed to start Connection service. Aug 16 13:09:29 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 16 13:09:29 systemd[1]: connman.service: Scheduled restart job, restart counter is at 4. Aug 16 13:09:29 systemd[1]: Stopped Connection service. Aug 16 13:09:29 systemd[1]: Starting Connection service... Aug 16 13:09:29 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 16 13:09:29 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 13:09:29 systemd[1]: Failed to start Connection service. Aug 16 13:09:30 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 16 13:09:30 systemd[1]: connman.service: Scheduled restart job, restart counter is at 5. Aug 16 13:09:30 systemd[1]: Stopped Connection service. Aug 16 13:09:30 systemd[1]: connman.service: Start request repeated too quickly. Aug 16 13:09:30 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 16 13:09:30 systemd[1]: Failed to start Connection service. Aug 17 10:35:45 systemd[1]: Starting Connection service... Aug 17 10:35:45 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 17 10:35:45 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 17 10:35:45 systemd[1]: Failed to start Connection service. Aug 17 10:35:46 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 17 10:35:46 systemd[1]: connman.service: Scheduled restart job, restart counter is at 1. Aug 17 10:35:46 systemd[1]: Stopped Connection service. Aug 17 10:35:46 systemd[1]: Starting Connection service... Aug 17 10:35:46 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 17 10:35:46 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 17 10:35:46 systemd[1]: Failed to start Connection service. Aug 17 10:35:46 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 17 10:35:46 systemd[1]: connman.service: Scheduled restart job, restart counter is at 2. Aug 17 10:35:46 systemd[1]: Stopped Connection service. Aug 17 10:35:46 systemd[1]: Starting Connection service... Aug 17 10:35:47 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 17 10:35:47 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 17 10:35:47 systemd[1]: Failed to start Connection service. Aug 17 10:35:47 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 17 10:35:47 systemd[1]: connman.service: Scheduled restart job, restart counter is at 3. Aug 17 10:35:47 systemd[1]: Stopped Connection service. Aug 17 10:35:47 systemd[1]: Starting Connection service... Aug 17 10:35:47 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 17 10:35:47 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 17 10:35:47 systemd[1]: Failed to start Connection service. Aug 17 10:35:47 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 17 10:35:47 systemd[1]: connman.service: Scheduled restart job, restart counter is at 4. Aug 17 10:35:47 systemd[1]: Stopped Connection service. Aug 17 10:35:47 systemd[1]: Starting Connection service... Aug 17 10:35:48 systemd[1]: connman.service: Main process exited, code=exited, status=1/FAILURE Aug 17 10:35:48 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 17 10:35:48 systemd[1]: Failed to start Connection service. Aug 17 10:35:48 systemd[1]: connman.service: Service RestartSec=100ms expired, scheduling restart. Aug 17 10:35:48 systemd[1]: connman.service: Scheduled restart job, restart counter is at 5. Aug 17 10:35:48 systemd[1]: Stopped Connection service. Aug 17 10:35:48 systemd[1]: connman.service: Start request repeated too quickly. Aug 17 10:35:48 systemd[1]: connman.service: Failed with result 'exit-code'. Aug 17 10:35:48 systemd[1]: Failed to start Connection service. ^ permalink raw reply [flat|nested] 28+ messages in thread
* Re: Unsalble cellular connection 2019-08-17 11:55 ` JH @ 2019-08-17 14:09 ` Jonas Bonn 2019-08-17 22:29 ` JH 0 siblings, 1 reply; 28+ messages in thread From: Jonas Bonn @ 2019-08-17 14:09 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 1213 bytes --] Hi JH, On 17/08/2019 13:55, JH wrote: > On 8/17/19, JH <jupiter.hce@gmail.com> wrote: >> On 8/16/19, Daniel Wagner <wagi@monom.org> wrote: >>> The NTP code is just telling it can't reach the server. This has no >>> direct connenction to the next entry. >> >> So that from NTP, don't need to worry about it. >> >>> This message is from the kernel via RTNL interface. The kernel tells >>> ConnMan the interface state has changed. >> >> OK, all from kernel, what could make the kernel to delete the link? What does the kernel log show? >> >> >>>> connmand[213]: Skipping disconnect of /ubloxqmi_0/context1, network is >>>> connecting. >>>> connmand[213]: ipconfig state 2 ipconfig method 1 >> >>> Your log does not contain the debug information (connmand -d). >> >> I attached two log files running in debug, doesn't seem >> >> $ OFONO_QMI_DEBUG=1 ofonod -d >> >> $ connmand -d > > Oops, pressed wrong key, both debug log files attached, looks even > less information from running ofono -n and connman -n by systemd. > It looks like you've multiple instances of connman and ofono running there, that's why you've got nothing in the logs. Give this another try. /Jonas ^ permalink raw reply [flat|nested] 28+ messages in thread
* Re: Unsalble cellular connection 2019-08-17 14:09 ` Jonas Bonn @ 2019-08-17 22:29 ` JH 0 siblings, 0 replies; 28+ messages in thread From: JH @ 2019-08-17 22:29 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 1449 bytes --] Hi Jonas, On 8/18/19, Jonas Bonn <jonas@norrbonn.se> wrote: >>> OK, all from kernel, what could make the kernel to delete the link? > > What does the kernel log show? ....... kernel: qmi_wwan 1-1:1.3: nonzero urb status received: -71 kernel: qmi_wwan 1-1:1.3: wdm_int_callback - 0 bytes kernel: qmi_wwan 1-1:1.3: wdm_int_callback - usb_submit_urb failed with result -19 kernel: qmi_wwan 1-1:1.3 wwan0: unregister 'qmi_wwan' usb-ci_hdrc.1-1, WWAN/QMI device ...... Attached full kernel log file. The test device is currently in link down and connected to WiFi. > It looks like you've multiple instances of connman and ofono running > there, that's why you've got nothing in the logs. Give this another try. Hmm, don't think so: # ps | grep connman | grep -v grep 3465 root 8948 S connmand -d # ps | grep ofono | grep -v grep 319 root 5656 S ofonod -d # systemctl status connman Active: inactive # systemctl status ofono Active: inactive # kill 3465 # ps | grep connman | grep -v grep # kill 319 # ps | grep ofono | grep -v grep # OFONO_QMI_DEBUG=1 ofonod -d # connmand -d # ps | grep connman | grep -v grep 4912 root 8944 S connmand -d # ps | grep ofono | grep -v grep 4910 root 5712 S ofonod -d # journalctl -u ofono > ofono.log # journalctl -u connman > connman.log same contexts in the log files, what I could be missing? Thanks Jonas - jh [-- Warning: decoded text below may be mangled, UTF-8 assumed --] [-- Attachment #2: kernel.log --] [-- Type: text/x-log, Size: 29923 bytes --] -- Logs begin at Fri 2019-08-16 07:45:56 UTC, end at Sat 2019-08-17 22:00:54 UTC. -- Aug 16 07:45:56 solar kernel: Booting Linux on physical CPU 0x0 Aug 16 07:45:56 solar kernel: Linux version 5.1.0-rc4 (oe-user@oe-host) (gcc version 8.2.0 (GCC)) #1 SMP Fri Aug 16 08:38:06 UTC 2019 Aug 16 07:45:56 solar kernel: CPU: ARMv7 Processor [410fc075] revision 5 (ARMv7), cr=10c5387d Aug 16 07:45:56 solar kernel: CPU: div instructions available: patching division code Aug 16 07:45:56 solar kernel: CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache Aug 16 07:45:56 solar kernel: OF: fdt: Machine model: Traverse PMU Aug 16 07:45:56 solar kernel: earlycon: ec_imx6q0 at MMIO 0x02020000 (options '') Aug 16 07:45:56 solar kernel: printk: bootconsole [ec_imx6q0] enabled Aug 16 07:45:56 solar kernel: Memory policy: Data cache writealloc Aug 16 07:45:56 solar kernel: cma: Reserved 64 MiB at 0x8c000000 Aug 16 07:45:56 solar kernel: On node 0 totalpages: 65536 Aug 16 07:45:56 solar kernel: Normal zone: 512 pages used for memmap Aug 16 07:45:56 solar kernel: Normal zone: 0 pages reserved Aug 16 07:45:56 solar kernel: Normal zone: 65536 pages, LIFO batch:15 Aug 16 07:45:56 solar kernel: random: get_random_bytes called from start_kernel+0x88/0x498 with crng_init=0 Aug 16 07:45:56 solar kernel: percpu: Embedded 18 pages/cpu @(ptrval) s42152 r8192 d23384 u73728 Aug 16 07:45:56 solar kernel: pcpu-alloc: s42152 r8192 d23384 u73728 alloc=18*4096 Aug 16 07:45:56 solar kernel: pcpu-alloc: [0] 0 Aug 16 07:45:56 solar kernel: Built 1 zonelists, mobility grouping on. Total pages: 65024 Aug 16 07:45:56 solar kernel: Kernel command line: console=ttymxc0,115200 earlycon init=/init mtdparts=gpmi-nand:4m(boot),2m(ubootenv),2m(dtb),32m(kernel1),32m(kernel2),-(ubi) root=ubi0:rootfs_data rw ubi.mtd=5,2048 noinitrd rootfstype=ubifs mem=256M rootwait=1 Aug 16 07:45:56 solar kernel: Dentry cache hash table entries: 32768 (order: 5, 131072 bytes) Aug 16 07:45:56 solar kernel: Inode-cache hash table entries: 16384 (order: 4, 65536 bytes) Aug 16 07:45:56 solar kernel: Memory: 167912K/262144K available (11264K kernel code, 957K rwdata, 4016K rodata, 1024K init, 7759K bss, 28696K reserved, 65536K cma-reserved, 0K highmem) Aug 16 07:45:56 solar kernel: SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1 Aug 16 07:45:56 solar kernel: Running RCU self tests Aug 16 07:45:56 solar kernel: rcu: Hierarchical RCU implementation. Aug 16 07:45:56 solar kernel: rcu: RCU event tracing is enabled. Aug 16 07:45:56 solar kernel: rcu: RCU lockdep checking is enabled. Aug 16 07:45:56 solar kernel: rcu: RCU restricting CPUs from NR_CPUS=4 to nr_cpu_ids=1. Aug 16 07:45:56 solar kernel: rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies. Aug 16 07:45:56 solar kernel: rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1 Aug 16 07:45:56 solar kernel: NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16 Aug 16 07:45:56 solar kernel: Switching to timer-based delay loop, resolution 41ns Aug 16 07:45:56 solar kernel: sched_clock: 32 bits at 24MHz, resolution 41ns, wraps every 89478484971ns Aug 16 07:45:56 solar kernel: clocksource: mxc_timer1: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 79635851949 ns Aug 16 07:45:56 solar kernel: Console: colour dummy device 80x30 Aug 16 07:45:56 solar kernel: Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar Aug 16 07:45:56 solar kernel: ... MAX_LOCKDEP_SUBCLASSES: 8 Aug 16 07:45:56 solar kernel: ... MAX_LOCK_DEPTH: 48 Aug 16 07:45:56 solar kernel: ... MAX_LOCKDEP_KEYS: 8191 Aug 16 07:45:56 solar kernel: ... CLASSHASH_SIZE: 4096 Aug 16 07:45:56 solar kernel: ... MAX_LOCKDEP_ENTRIES: 32768 Aug 16 07:45:56 solar kernel: ... MAX_LOCKDEP_CHAINS: 65536 Aug 16 07:45:56 solar kernel: ... CHAINHASH_SIZE: 32768 Aug 16 07:45:56 solar kernel: memory used by lock dependency info: 5243 kB Aug 16 07:45:56 solar kernel: per task-struct memory footprint: 1536 bytes Aug 16 07:45:56 solar kernel: Calibrating delay loop (skipped), value calculated using timer frequency.. 48.00 BogoMIPS (lpj=240000) Aug 16 07:45:56 solar kernel: pid_max: default: 32768 minimum: 301 Aug 16 07:45:56 solar kernel: Mount-cache hash table entries: 1024 (order: 0, 4096 bytes) Aug 16 07:45:56 solar kernel: Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes) Aug 16 07:45:56 solar kernel: *** VALIDATE proc *** Aug 16 07:45:56 solar kernel: *** VALIDATE cgroup1 *** Aug 16 07:45:56 solar kernel: *** VALIDATE cgroup2 *** Aug 16 07:45:56 solar kernel: CPU: Testing write buffer coherency: ok Aug 16 07:45:56 solar kernel: /cpus/cpu@0 missing clock-frequency property Aug 16 07:45:56 solar kernel: CPU0: thread -1, cpu 0, socket 0, mpidr 80000000 Aug 16 07:45:56 solar kernel: Setting up static identity map for 0x80100000 - 0x80100078 Aug 16 07:45:56 solar kernel: rcu: Hierarchical SRCU implementation. Aug 16 07:45:56 solar kernel: smp: Bringing up secondary CPUs ... Aug 16 07:45:56 solar kernel: smp: Brought up 1 node, 1 CPU Aug 16 07:45:56 solar kernel: SMP: Total of 1 processors activated (48.00 BogoMIPS). Aug 16 07:45:56 solar kernel: CPU: All CPU(s) started in SVC mode. Aug 16 07:45:56 solar kernel: devtmpfs: initialized Aug 16 07:45:56 solar kernel: VFP support v0.3: implementor 41 architecture 2 part 30 variant 7 rev 5 Aug 16 07:45:56 solar kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns Aug 16 07:45:56 solar kernel: futex hash table entries: 256 (order: 2, 16384 bytes) Aug 16 07:45:56 solar kernel: pinctrl core: initialized pinctrl subsystem Aug 16 07:45:56 solar kernel: NET: Registered protocol family 16 Aug 16 07:45:56 solar kernel: DMA: preallocated 256 KiB pool for atomic coherent allocations Aug 16 07:45:56 solar kernel: cpuidle: using governor menu Aug 16 07:45:56 solar kernel: vdd3p0: supplied by regulator-dummy Aug 16 07:45:56 solar kernel: cpu: supplied by regulator-dummy Aug 16 07:45:56 solar kernel: vddsoc: supplied by regulator-dummy Aug 16 07:45:56 solar kernel: No ATAGs? Aug 16 07:45:56 solar kernel: hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers. Aug 16 07:45:56 solar kernel: hw-breakpoint: maximum watchpoint size is 8 bytes. Aug 16 07:45:56 solar kernel: imx6ul-pinctrl 20e0000.iomuxc: initialized IMX pinctrl driver Aug 16 07:45:56 solar kernel: imx6ul-pinctrl 2290000.iomuxc-snvs: no groups defined in /soc/aips-bus@2200000/iomuxc-snvs@2290000 Aug 16 07:45:56 solar kernel: imx6ul-pinctrl 2290000.iomuxc-snvs: initialized IMX pinctrl driver Aug 16 07:45:56 solar kernel: mxs-dma 1804000.dma-apbh: initialized Aug 16 07:45:56 solar kernel: vgaarb: loaded Aug 16 07:45:56 solar kernel: SCSI subsystem initialized Aug 16 07:45:56 solar kernel: libata version 3.00 loaded. Aug 16 07:45:56 solar kernel: usbcore: registered new interface driver usbfs Aug 16 07:45:56 solar kernel: usbcore: registered new interface driver hub Aug 16 07:45:56 solar kernel: usbcore: registered new device driver usb Aug 16 07:45:56 solar kernel: media: Linux media interface: v0.10 Aug 16 07:45:56 solar kernel: videodev: Linux video capture interface: v2.00 Aug 16 07:45:56 solar kernel: pps_core: LinuxPPS API ver. 1 registered Aug 16 07:45:56 solar kernel: pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it> Aug 16 07:45:56 solar kernel: PTP clock support registered Aug 16 07:45:56 solar kernel: Advanced Linux Sound Architecture Driver Initialized. Aug 16 07:45:56 solar kernel: Bluetooth: Core ver 2.22 Aug 16 07:45:56 solar kernel: NET: Registered protocol family 31 Aug 16 07:45:56 solar kernel: Bluetooth: HCI device and connection manager initialized Aug 16 07:45:56 solar kernel: Bluetooth: HCI socket layer initialized Aug 16 07:45:56 solar kernel: Bluetooth: L2CAP socket layer initialized Aug 16 07:45:56 solar kernel: Bluetooth: SCO socket layer initialized Aug 16 07:45:56 solar kernel: clocksource: Switched to clocksource mxc_timer1 Aug 16 07:45:56 solar kernel: VFS: Disk quotas dquot_6.6.0 Aug 16 07:45:56 solar kernel: VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) Aug 16 07:45:56 solar kernel: NET: Registered protocol family 2 Aug 16 07:45:56 solar kernel: tcp_listen_portaddr_hash hash table entries: 128 (order: 0, 5120 bytes) Aug 16 07:45:56 solar kernel: TCP established hash table entries: 2048 (order: 1, 8192 bytes) Aug 16 07:45:56 solar kernel: TCP bind hash table entries: 2048 (order: 4, 73728 bytes) Aug 16 07:45:56 solar kernel: TCP: Hash tables configured (established 2048 bind 2048) Aug 16 07:45:56 solar kernel: UDP hash table entries: 256 (order: 2, 20480 bytes) Aug 16 07:45:56 solar kernel: UDP-Lite hash table entries: 256 (order: 2, 20480 bytes) Aug 16 07:45:56 solar kernel: NET: Registered protocol family 1 Aug 16 07:45:56 solar kernel: RPC: Registered named UNIX socket transport module. Aug 16 07:45:56 solar kernel: RPC: Registered udp transport module. Aug 16 07:45:56 solar kernel: RPC: Registered tcp transport module. Aug 16 07:45:56 solar kernel: RPC: Registered tcp NFSv4.1 backchannel transport module. Aug 16 07:45:56 solar kernel: PCI: CLS 0 bytes, default 64 Aug 16 07:45:56 solar kernel: hw perfevents: enabled with armv7_cortex_a7 PMU driver, 5 counters available Aug 16 07:45:56 solar kernel: Initialise system trusted keyrings Aug 16 07:45:56 solar kernel: workingset: timestamp_bits=30 max_order=16 bucket_order=0 Aug 16 07:45:56 solar kernel: NFS: Registering the id_resolver key type Aug 16 07:45:56 solar kernel: Key type id_resolver registered Aug 16 07:45:56 solar kernel: Key type id_legacy registered Aug 16 07:45:56 solar kernel: jffs2: version 2.2. (NAND) © 2001-2006 Red Hat, Inc. Aug 16 07:45:56 solar kernel: fuse init (API version 7.29) Aug 16 07:45:56 solar kernel: Key type asymmetric registered Aug 16 07:45:56 solar kernel: Asymmetric key parser 'x509' registered Aug 16 07:45:56 solar kernel: io scheduler mq-deadline registered Aug 16 07:45:56 solar kernel: io scheduler kyber registered Aug 16 07:45:56 solar kernel: imx-sdma 20ec000.sdma: Direct firmware load for imx/sdma/sdma-imx6q.bin failed with error -2 Aug 16 07:45:56 solar kernel: imx-sdma 20ec000.sdma: Falling back to syfs fallback for: imx/sdma/sdma-imx6q.bin Aug 16 07:45:56 solar kernel: 2020000.serial: ttymxc0 at MMIO 0x2020000 (irq = 22, base_baud = 5000000) is a IMX Aug 16 07:45:56 solar kernel: printk: console [ttymxc0] enabled Aug 16 07:45:56 solar kernel: printk: bootconsole [ec_imx6q0] disabled Aug 16 07:45:56 solar kernel: random: fast init done Aug 16 07:45:56 solar kernel: 21e8000.serial: ttymxc1 at MMIO 0x21e8000 (irq = 50, base_baud = 5000000) is a IMX Aug 16 07:45:56 solar kernel: 21f0000.serial: ttymxc3 at MMIO 0x21f0000 (irq = 51, base_baud = 5000000) is a IMX Aug 16 07:45:56 solar kernel: brd: module loaded Aug 16 07:45:56 solar kernel: loop: module loaded Aug 16 07:45:56 solar kernel: nand: device found, Manufacturer ID: 0xef, Chip ID: 0xda Aug 16 07:45:56 solar kernel: nand: Winbond W29N02GV Aug 16 07:45:56 solar kernel: nand: 256 MiB, SLC, erase size: 128 KiB, page size: 2048, OOB size: 64 Aug 16 07:45:56 solar kernel: Bad block table found at page 131008, version 0x01 Aug 16 07:45:56 solar kernel: Bad block table found at page 130944, version 0x01 Aug 16 07:45:56 solar kernel: 6 cmdlinepart partitions found on MTD device gpmi-nand Aug 16 07:45:56 solar kernel: Creating 6 MTD partitions on "gpmi-nand": Aug 16 07:45:56 solar kernel: 0x000000000000-0x000000400000 : "boot" Aug 16 07:45:56 solar kernel: 0x000000400000-0x000000600000 : "ubootenv" Aug 16 07:45:56 solar kernel: 0x000000600000-0x000000800000 : "dtb" Aug 16 07:45:56 solar kernel: 0x000000800000-0x000002800000 : "kernel1" Aug 16 07:45:56 solar kernel: 0x000002800000-0x000004800000 : "kernel2" Aug 16 07:45:56 solar kernel: 0x000004800000-0x000010000000 : "ubi" Aug 16 07:45:56 solar kernel: gpmi-nand 1806000.gpmi-nand: driver registered. Aug 16 07:45:56 solar kernel: libphy: Fixed MDIO Bus: probed Aug 16 07:45:56 solar kernel: CAN device driver interface Aug 16 07:45:56 solar kernel: usbcore: registered new interface driver r8152 Aug 16 07:45:56 solar kernel: usbcore: registered new interface driver lan78xx Aug 16 07:45:56 solar kernel: usbcore: registered new interface driver asix Aug 16 07:45:56 solar kernel: usbcore: registered new interface driver ax88179_178a Aug 16 07:45:56 solar kernel: usbcore: registered new interface driver cdc_ether Aug 16 07:45:56 solar kernel: usbcore: registered new interface driver smsc95xx Aug 16 07:45:56 solar kernel: usbcore: registered new interface driver net1080 Aug 16 07:45:56 solar kernel: usbcore: registered new interface driver cdc_subset Aug 16 07:45:56 solar kernel: usbcore: registered new interface driver zaurus Aug 16 07:45:56 solar kernel: usbcore: registered new interface driver MOSCHIP usb-ethernet driver Aug 16 07:45:56 solar kernel: usbcore: registered new interface driver cdc_ncm Aug 16 07:45:56 solar kernel: usbcore: registered new interface driver qmi_wwan Aug 16 07:45:56 solar kernel: ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver Aug 16 07:45:56 solar kernel: ehci-pci: EHCI PCI platform driver Aug 16 07:45:56 solar kernel: ehci-mxc: Freescale On-Chip EHCI Host driver Aug 16 07:45:56 solar kernel: usbcore: registered new interface driver cdc_wdm Aug 16 07:45:56 solar kernel: usbcore: registered new interface driver usb-storage Aug 16 07:45:56 solar kernel: imx_usb 2184000.usb: No over current polarity defined Aug 16 07:45:56 solar kernel: imx_usb 2184200.usb: 2184200.usb supply vbus not found, using dummy regulator Aug 16 07:45:56 solar kernel: ci_hdrc ci_hdrc.1: EHCI Host Controller Aug 16 07:45:56 solar kernel: ci_hdrc ci_hdrc.1: new USB bus registered, assigned bus number 1 Aug 16 07:45:56 solar kernel: ci_hdrc ci_hdrc.1: USB 2.0 started, EHCI 1.00 Aug 16 07:45:56 solar kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.01 Aug 16 07:45:56 solar kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Aug 16 07:45:56 solar kernel: usb usb1: Product: EHCI Host Controller Aug 16 07:45:56 solar kernel: usb usb1: Manufacturer: Linux 5.1.0-rc4 ehci_hcd Aug 16 07:45:56 solar kernel: usb usb1: SerialNumber: ci_hdrc.1 Aug 16 07:45:56 solar kernel: hub 1-0:1.0: USB hub found Aug 16 07:45:56 solar kernel: hub 1-0:1.0: 1 port detected Aug 16 07:45:56 solar kernel: input: 20cc000.snvs:snvs-powerkey as /devices/soc0/soc/2000000.aips-bus/20cc000.snvs/20cc000.snvs:snvs-powerkey/input/input0 Aug 16 07:45:56 solar kernel: snvs_rtc 20cc000.snvs:snvs-rtc-lp: registered as rtc0 Aug 16 07:45:56 solar kernel: i2c /dev entries driver Aug 16 07:45:56 solar kernel: imx2-wdt 20bc000.wdog: timeout 60 sec (nowayout=0) Aug 16 07:45:56 solar kernel: Bluetooth: HCI UART driver ver 2.3 Aug 16 07:45:56 solar kernel: Bluetooth: HCI UART protocol H4 registered Aug 16 07:45:56 solar kernel: Bluetooth: HCI UART protocol LL registered Aug 16 07:45:56 solar kernel: sdhci: Secure Digital Host Controller Interface driver Aug 16 07:45:56 solar kernel: sdhci: Copyright(c) Pierre Ossman Aug 16 07:45:56 solar kernel: sdhci-pltfm: SDHCI platform and OF driver helper Aug 16 07:45:56 solar kernel: mmc0: SDHCI controller on 2190000.usdhc [2190000.usdhc] using ADMA Aug 16 07:45:56 solar kernel: usbcore: registered new interface driver usbhid Aug 16 07:45:56 solar kernel: usbhid: USB HID core driver Aug 16 07:45:56 solar kernel: NET: Registered protocol family 10 Aug 16 07:45:56 solar kernel: Segment Routing with IPv6 Aug 16 07:45:56 solar kernel: sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver Aug 16 07:45:56 solar kernel: NET: Registered protocol family 17 Aug 16 07:45:56 solar kernel: can: controller area network core (rev 20170425 abi 9) Aug 16 07:45:56 solar kernel: NET: Registered protocol family 29 Aug 16 07:45:56 solar kernel: can: raw protocol (rev 20170425) Aug 16 07:45:56 solar kernel: can: broadcast manager protocol (rev 20170425 t) Aug 16 07:45:56 solar kernel: mmc0: Tuning failed, falling back to fixed sampling clock Aug 16 07:45:56 solar kernel: can: netlink gateway (rev 20170425) max_hops=1 Aug 16 07:45:56 solar kernel: Key type dns_resolver registered Aug 16 07:45:56 solar kernel: cpu cpu0: failed to disable 696MHz OPP Aug 16 07:45:56 solar kernel: mmc0: new ultra high speed SDR104 SDIO card at address 0001 Aug 16 07:45:56 solar kernel: Registering SWP/SWPB emulation handler Aug 16 07:45:56 solar kernel: Loading compiled-in X.509 certificates Aug 16 07:45:56 solar kernel: imx_thermal tempmon: Commercial CPU temperature grade - max:95C critical:90C passive:85C Aug 16 07:45:56 solar kernel: ubi0: default fastmap pool size: 70 Aug 16 07:45:56 solar kernel: ubi0: default fastmap WL pool size: 35 Aug 16 07:45:56 solar kernel: ubi0: attaching mtd5 Aug 16 07:45:56 solar kernel: ubi0: scanning is finished Aug 16 07:45:56 solar kernel: ubi0: attached mtd5 (name "ubi", size 184 MiB) Aug 16 07:45:56 solar kernel: ubi0: PEB size: 131072 bytes (128 KiB), LEB size: 126976 bytes Aug 16 07:45:56 solar kernel: ubi0: min./max. I/O unit sizes: 2048/2048, sub-page size 2048 Aug 16 07:45:56 solar kernel: ubi0: VID header offset: 2048 (aligned 2048), data offset: 4096 Aug 16 07:45:56 solar kernel: ubi0: good PEBs: 1468, bad PEBs: 4, corrupted PEBs: 0 Aug 16 07:45:56 solar kernel: ubi0: user volume: 1, internal volumes: 1, max. volumes count: 128 Aug 16 07:45:56 solar kernel: ubi0: max/mean erase counter: 13/7, WL threshold: 4096, image sequence number: 910482982 Aug 16 07:45:56 solar kernel: ubi0: available PEBs: 104, total reserved PEBs: 1364, PEBs reserved for bad PEB handling: 36 Aug 16 07:45:56 solar kernel: ubi0: background thread "ubi_bgt0d" started, PID 109 Aug 16 07:45:56 solar kernel: snvs_rtc 20cc000.snvs:snvs-rtc-lp: setting system clock to 1970-01-01T00:00:01 UTC (1) Aug 16 07:45:56 solar kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database Aug 16 07:45:56 solar kernel: cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' Aug 16 07:45:56 solar kernel: platform regulatory.0: Direct firmware load for regulatory.db failed with error -2 Aug 16 07:45:56 solar kernel: platform regulatory.0: Falling back to syfs fallback for: regulatory.db Aug 16 07:45:56 solar kernel: ALSA device list: Aug 16 07:45:56 solar kernel: No soundcards found. Aug 16 07:45:56 solar kernel: UBIFS (ubi0:0): Mounting in unauthenticated mode Aug 16 07:45:56 solar kernel: UBIFS (ubi0:0): background thread "ubifs_bgt0_0" started, PID 115 Aug 16 07:45:56 solar kernel: random: crng init done Aug 16 07:45:56 solar kernel: UBIFS (ubi0:0): UBIFS: mounted UBI device 0, volume 0, name "rootfs_data" Aug 16 07:45:56 solar kernel: UBIFS (ubi0:0): LEB size: 126976 bytes (124 KiB), min./max. I/O unit sizes: 2048 bytes/2048 bytes Aug 16 07:45:56 solar kernel: UBIFS (ubi0:0): FS size: 166338560 bytes (158 MiB, 1310 LEBs), journal size 8380416 bytes (7 MiB, 66 LEBs) Aug 16 07:45:56 solar kernel: UBIFS (ubi0:0): reserved for root: 4952683 bytes (4836 KiB) Aug 16 07:45:56 solar kernel: UBIFS (ubi0:0): media format: w4/r0 (latest is w5/r0), UUID E65F9649-D208-4786-A4A8-8E9BFF88F57C, small LPT model Aug 16 07:45:56 solar kernel: VFS: Mounted root (ubifs filesystem) on device 0:13. Aug 16 07:45:56 solar kernel: devtmpfs: mounted Aug 16 07:45:56 solar kernel: Freeing unused kernel memory: 1024K Aug 16 07:45:56 solar kernel: Run /init as init process Aug 16 07:46:11 solar kernel: evbug: Connected device: input0 (20cc000.snvs:snvs-powerkey at snvs-pwrkey/input0) Aug 16 07:46:12 solar kernel: usb 1-1: new high-speed USB device number 2 using ci_hdrc Aug 16 07:46:12 solar kernel: usb 1-1: New USB device found, idVendor=05c6, idProduct=90b2, bcdDevice= 0.00 Aug 16 07:46:12 solar kernel: usb 1-1: New USB device strings: Mfr=3, Product=2, SerialNumber=4 Aug 16 07:46:12 solar kernel: usb 1-1: Product: Qualcomm CDMA Technologies MSM Aug 16 07:46:12 solar kernel: usb 1-1: Manufacturer: Qualcomm, Incorporated Aug 16 07:46:12 solar kernel: usb 1-1: SerialNumber: 5ff10299 Aug 16 07:46:12 solar kernel: qmi_wwan 1-1:1.3: cdc-wdm0: USB WDM device Aug 16 07:46:12 solar kernel: qmi_wwan 1-1:1.3 wwan0: register 'qmi_wwan' at usb-ci_hdrc.1-1, WWAN/QMI device, f6:0d:90:fa:af:24 Aug 16 07:46:13 solar kernel: usbcore: registered new interface driver usbserial_generic Aug 16 07:46:13 solar kernel: usbserial: USB Serial support registered for generic Aug 16 07:46:13 solar kernel: usbcore: registered new interface driver option Aug 16 07:46:13 solar kernel: usbserial: USB Serial support registered for GSM modem (1-port) Aug 16 07:46:13 solar kernel: option 1-1:1.0: GSM modem (1-port) converter detected Aug 16 07:46:13 solar kernel: usb 1-1: GSM modem (1-port) converter now attached to ttyUSB0 Aug 16 07:46:13 solar kernel: option 1-1:1.2: GSM modem (1-port) converter detected Aug 16 07:46:13 solar kernel: usb 1-1: GSM modem (1-port) converter now attached to ttyUSB1 Aug 16 07:46:17 solar kernel: mwifiex_sdio mmc0:0001:1: info: FW download over, size 695532 bytes Aug 16 07:46:17 solar kernel: mwifiex_sdio mmc0:0001:1: WLAN FW is active Aug 16 07:46:17 solar kernel: mwifiex_sdio mmc0:0001:1: CMD_RESP: cmd 0x242 error, result=0x2 Aug 16 07:46:17 solar kernel: mwifiex_sdio mmc0:0001:1: mwifiex_process_cmdresp: cmd 0x242 failed during initialization Aug 16 07:46:17 solar kernel: mwifiex_sdio mmc0:0001:1: info: MWIFIEX VERSION: mwifiex 1.0 (15.68.7.p71) Aug 16 07:46:17 solar kernel: mwifiex_sdio mmc0:0001:1: driver_version = mwifiex 1.0 (15.68.7.p71) Aug 16 07:46:43 solar kernel: usb 1-1: USB disconnect, device number 2 Aug 16 07:46:43 solar kernel: option1 ttyUSB0: GSM modem (1-port) converter now disconnected from ttyUSB0 Aug 16 07:46:43 solar kernel: option 1-1:1.0: device disconnected Aug 16 07:46:43 solar kernel: option1 ttyUSB1: GSM modem (1-port) converter now disconnected from ttyUSB1 Aug 16 07:46:43 solar kernel: option 1-1:1.2: device disconnected Aug 16 07:46:44 solar kernel: qmi_wwan 1-1:1.3 wwan0: unregister 'qmi_wwan' usb-ci_hdrc.1-1, WWAN/QMI device Aug 16 07:46:47 solar kernel: usb 1-1: new high-speed USB device number 3 using ci_hdrc Aug 16 07:46:47 solar kernel: usb 1-1: New USB device found, idVendor=05c6, idProduct=90b2, bcdDevice= 0.00 Aug 16 07:46:47 solar kernel: usb 1-1: New USB device strings: Mfr=3, Product=2, SerialNumber=4 Aug 16 07:46:47 solar kernel: usb 1-1: Product: Qualcomm CDMA Technologies MSM Aug 16 07:46:47 solar kernel: usb 1-1: Manufacturer: Qualcomm, Incorporated Aug 16 07:46:47 solar kernel: usb 1-1: SerialNumber: 5ff10299 Aug 16 07:46:47 solar kernel: option 1-1:1.0: GSM modem (1-port) converter detected Aug 16 07:46:48 solar kernel: usb 1-1: GSM modem (1-port) converter now attached to ttyUSB0 Aug 16 07:46:48 solar kernel: option 1-1:1.2: GSM modem (1-port) converter detected Aug 16 07:46:48 solar kernel: usb 1-1: GSM modem (1-port) converter now attached to ttyUSB1 Aug 16 07:46:48 solar kernel: qmi_wwan 1-1:1.3: cdc-wdm0: USB WDM device Aug 16 07:46:48 solar kernel: qmi_wwan 1-1:1.3 wwan0: register 'qmi_wwan' at usb-ci_hdrc.1-1, WWAN/QMI device, f6:0d:90:fa:af:24 Aug 16 07:46:51 solar kernel: imx-sdma 20ec000.sdma: external firmware not found, using ROM firmware Aug 16 07:46:56 solar kernel: cfg80211: failed to load regulatory.db Aug 16 07:46:56 solar kernel: cfg80211: failed to load regulatory.db Aug 16 11:31:09 solar kernel: ieee80211 phy0: mwifiex_cfg80211_sched_scan_start : Invalid Sched_scan parameters Aug 16 11:32:30 solar kernel: ieee80211 phy0: mwifiex_cfg80211_sched_scan_start : Invalid Sched_scan parameters Aug 16 11:36:33 solar kernel: ieee80211 phy0: mwifiex_cfg80211_sched_scan_start : Invalid Sched_scan parameters Aug 16 11:41:33 solar kernel: ieee80211 phy0: mwifiex_cfg80211_sched_scan_start : Invalid Sched_scan parameters Aug 16 11:46:33 solar kernel: ieee80211 phy0: mwifiex_cfg80211_sched_scan_start : Invalid Sched_scan parameters Aug 16 11:51:33 solar kernel: ieee80211 phy0: mwifiex_cfg80211_sched_scan_start : Invalid Sched_scan parameters Aug 16 11:56:33 solar kernel: ieee80211 phy0: mwifiex_cfg80211_sched_scan_start : Invalid Sched_scan parameters Aug 16 12:01:33 solar kernel: ieee80211 phy0: mwifiex_cfg80211_sched_scan_start : Invalid Sched_scan parameters Aug 16 12:06:33 solar kernel: ieee80211 phy0: mwifiex_cfg80211_sched_scan_start : Invalid Sched_scan parameters Aug 16 12:11:33 solar kernel: ieee80211 phy0: mwifiex_cfg80211_sched_scan_start : Invalid Sched_scan parameters Aug 16 12:16:33 solar kernel: ieee80211 phy0: mwifiex_cfg80211_sched_scan_start : Invalid Sched_scan parameters Aug 16 12:21:33 solar kernel: ieee80211 phy0: mwifiex_cfg80211_sched_scan_start : Invalid Sched_scan parameters Aug 16 12:26:33 solar kernel: ieee80211 phy0: mwifiex_cfg80211_sched_scan_start : Invalid Sched_scan parameters Aug 16 12:32:00 solar kernel: mwifiex_sdio mmc0:0001:1: info: trying to associate to 'JupiterIoT' bssid 34:08:04:12:b1:a2 Aug 16 12:32:00 solar kernel: mwifiex_sdio mmc0:0001:1: info: associated to bssid 34:08:04:12:b1:a2 successfully Aug 16 12:32:00 solar kernel: IPv6: ADDRCONF(NETDEV_CHANGE): mlan0: link becomes ready Aug 17 05:08:27 solar kernel: mwifiex_sdio mmc0:0001:1: info: successfully disconnected from 34:08:04:12:b1:a2: reason code 3 Aug 17 08:32:31 solar kernel: mwifiex_sdio mmc0:0001:1: info: trying to associate to 'JupiterIoT' bssid 34:08:04:12:b1:a2 Aug 17 08:32:31 solar kernel: mwifiex_sdio mmc0:0001:1: info: associated to bssid 34:08:04:12:b1:a2 successfully Aug 17 08:32:31 solar kernel: IPv6: ADDRCONF(NETDEV_CHANGE): mlan0: link becomes ready Aug 17 08:51:46 solar kernel: usb 1-1: USB disconnect, device number 3 Aug 17 08:51:46 solar kernel: option1 ttyUSB0: GSM modem (1-port) converter now disconnected from ttyUSB0 Aug 17 08:51:46 solar kernel: option 1-1:1.0: device disconnected Aug 17 08:51:46 solar kernel: option1 ttyUSB1: GSM modem (1-port) converter now disconnected from ttyUSB1 Aug 17 08:51:46 solar kernel: option 1-1:1.2: device disconnected Aug 17 08:51:46 solar kernel: qmi_wwan 1-1:1.3: nonzero urb status received: -71 Aug 17 08:51:46 solar kernel: qmi_wwan 1-1:1.3: wdm_int_callback - 0 bytes Aug 17 08:51:46 solar kernel: qmi_wwan 1-1:1.3: wdm_int_callback - usb_submit_urb failed with result -19 Aug 17 08:51:46 solar kernel: qmi_wwan 1-1:1.3 wwan0: unregister 'qmi_wwan' usb-ci_hdrc.1-1, WWAN/QMI device Aug 17 08:51:49 solar kernel: usb 1-1: new high-speed USB device number 4 using ci_hdrc Aug 17 08:51:50 solar kernel: usb 1-1: New USB device found, idVendor=05c6, idProduct=90b2, bcdDevice= 0.00 Aug 17 08:51:50 solar kernel: usb 1-1: New USB device strings: Mfr=3, Product=2, SerialNumber=4 Aug 17 08:51:50 solar kernel: usb 1-1: Product: Qualcomm CDMA Technologies MSM Aug 17 08:51:50 solar kernel: usb 1-1: Manufacturer: Qualcomm, Incorporated Aug 17 08:51:50 solar kernel: usb 1-1: SerialNumber: 5ff10299 Aug 17 08:51:50 solar kernel: option 1-1:1.0: GSM modem (1-port) converter detected Aug 17 08:51:50 solar kernel: usb 1-1: GSM modem (1-port) converter now attached to ttyUSB0 Aug 17 08:51:50 solar kernel: option 1-1:1.2: GSM modem (1-port) converter detected Aug 17 08:51:50 solar kernel: usb 1-1: GSM modem (1-port) converter now attached to ttyUSB1 Aug 17 08:51:50 solar kernel: qmi_wwan 1-1:1.3: cdc-wdm0: USB WDM device Aug 17 08:51:50 solar kernel: qmi_wwan 1-1:1.3 wwan0: register 'qmi_wwan' at usb-ci_hdrc.1-1, WWAN/QMI device, f6:0d:90:fa:af:24 Aug 17 10:34:44 solar kernel: mwifiex_sdio mmc0:0001:1: info: successfully disconnected from 34:08:04:12:b1:a2: reason code 3 Aug 17 10:35:01 solar kernel: mwifiex_sdio mmc0:0001:1: info: trying to associate to 'JupiterIoT' bssid 34:08:04:12:b1:a2 Aug 17 10:35:01 solar kernel: mwifiex_sdio mmc0:0001:1: info: associated to bssid 34:08:04:12:b1:a2 successfully Aug 17 10:35:01 solar kernel: IPv6: ADDRCONF(NETDEV_CHANGE): mlan0: link becomes ready Aug 17 10:35:03 solar kernel: mwifiex_sdio mmc0:0001:1: info: successfully disconnected from 34:08:04:12:b1:a2: reason code 3 Aug 17 11:32:43 solar kernel: usb 1-1: USB disconnect, device number 4 Aug 17 11:32:43 solar kernel: option1 ttyUSB0: GSM modem (1-port) converter now disconnected from ttyUSB0 Aug 17 11:32:43 solar kernel: option 1-1:1.0: device disconnected Aug 17 11:32:43 solar kernel: option1 ttyUSB1: GSM modem (1-port) converter now disconnected from ttyUSB1 Aug 17 11:32:43 solar kernel: option 1-1:1.2: device disconnected Aug 17 11:32:44 solar kernel: qmi_wwan 1-1:1.3: nonzero urb status received: -71 Aug 17 11:32:44 solar kernel: qmi_wwan 1-1:1.3: wdm_int_callback - 0 bytes Aug 17 11:32:44 solar kernel: qmi_wwan 1-1:1.3: wdm_int_callback - usb_submit_urb failed with result -19 Aug 17 11:32:44 solar kernel: qmi_wwan 1-1:1.3 wwan0: unregister 'qmi_wwan' usb-ci_hdrc.1-1, WWAN/QMI device Aug 17 11:32:44 solar kernel: usb 1-1: new high-speed USB device number 5 using ci_hdrc Aug 17 11:32:45 solar kernel: usb 1-1: New USB device found, idVendor=05c6, idProduct=90b2, bcdDevice= 0.00 Aug 17 11:32:45 solar kernel: usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Aug 17 11:32:45 solar kernel: usb 1-1: Product: QHSUSB__BULK Aug 17 11:32:45 solar kernel: usb 1-1: Manufacturer: Qualcomm CDMA Technologies MSM Aug 17 11:32:45 solar kernel: usb 1-1: SerialNumber: 5ff10299 Aug 17 11:32:45 solar kernel: option 1-1:1.0: GSM modem (1-port) converter detected Aug 17 11:32:45 solar kernel: usb 1-1: GSM modem (1-port) converter now attached to ttyUSB0 Aug 17 11:32:48 solar kernel: mwifiex_sdio mmc0:0001:1: info: trying to associate to 'JupiterIoT' bssid 34:08:04:12:b1:a2 Aug 17 11:32:48 solar kernel: mwifiex_sdio mmc0:0001:1: info: associated to bssid 34:08:04:12:b1:a2 successfully Aug 17 11:32:48 solar kernel: IPv6: ADDRCONF(NETDEV_CHANGE): mlan0: link becomes ready ^ permalink raw reply [flat|nested] 28+ messages in thread
* Unsalble cellular connection
@ 2019-08-01 11:01 JH
2019-08-01 18:16 ` Giacinto Cifelli
0 siblings, 1 reply; 28+ messages in thread
From: JH @ 2019-08-01 11:01 UTC (permalink / raw)
To: ofono
[-- Attachment #1: Type: text/plain, Size: 3781 bytes --]
Hi,
I have a device connect to 4G LTE, it was in good connection status on
start up, after a couple of hours, it dropped LTE connection, the
ofono did not show any errors, but connman had lots of error messages
at following, could any one help to explain what could be the problem?
Could it be ofono issue or connman issue? The device has small flash
size which don't have enough space to debug tools.
# journalctl -u ofono
-- Logs begin at Fri 2019-07-05 05:07:42 UTC, end at Thu 2019-08-01 10:42:49 UT-
Aug 01 07:49:47 systemd[1]: Starting Telephony service...
Aug 01 07:49:48 ofonod[188]: oFono version 1.24
Aug 01 07:49:48 systemd[1]: Started Telephony service.
Aug 01 07:49:53 ofonod[188]: Interface org.ofono.AllowedAccessPoints not t
Aug 01 07:49:57 ofonod[188]: LTE attach IP type: 0
Aug 01 08:09:39 ofonod[188]: LTE attach IP type: 0
# journalctl -u connman
.........
Aug 01 08:09:39 connmand[181]: Skipping disconnect of
/ubloxqmi_0/context1, network is connecting.
Aug 01 08:09:39 connmand[181]: ipconfig state 2 ipconfig method 1
Aug 01 08:09:39 connmand[181]: wwan0 {RX} 45 packets 7963 bytes
Aug 01 08:09:39 connmand[181]: wwan0 {TX} 56 packets 4730 bytes
Aug 01 08:09:39 connmand[181]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP>
Aug 01 08:09:39 connmand[181]: wwan0 {newlink} index 4 address
00:00:00:00:00:00 mtu 1500
Aug 01 08:09:39 connmand[181]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN>
Aug 01 08:09:39 connmand[181]: ipconfig state 3 ipconfig method 1
Aug 01 08:09:39 connmand[181]: wwan0 {add} address 10.114.23.145/30
label wwan0 family 2
Aug 01 08:09:39 connmand[181]: wwan0 {add} route 10.114.23.144 gw
0.0.0.0 scope 253 <LINK>
Aug 01 08:09:39 connmand[181]: wwan0 {add} route 10.114.23.146 gw
0.0.0.0 scope 253 <LINK>
Aug 01 08:09:39 connmand[181]: wwan0 {add} route 10.4.58.204 gw
10.114.23.146 scope 0 <UNIVERSE>
Aug 01 08:09:39 connmand[181]: wwan0 {add} route 0.0.0.0 gw
10.114.23.146 scope 0 <UNIVERSE>
Aug 01 08:09:45 connmand[181]: Online check failed for 0xa71cf8 Telstra
Aug 01 09:34:10 connmand[181]: wwan0 {RX} 140 packets 15185 bytes
Aug 01 09:34:10 connmand[181]: wwan0 {TX} 158 packets 12440 bytes
Aug 01 09:34:10 connmand[181]: wwan0 {update} flags 4240 <DOWN>
Aug 01 09:34:11 connmand[181]: wwan0 {newlink} index 4 address
00:00:00:00:00:00 mtu 1500
Aug 01 09:34:11 connmand[181]: wwan0 {newlink} index 4 operstate 2 <DOWN>
Aug 01 09:34:11 connmand[181]: Time request for server 10.114.23.146
failed (101/Network is unreachable)
Aug 01 09:34:11 connmand[181]: wwan0 {del} address 10.114.23.145/30 label wwan0
Aug 01 09:34:11 connmand[181]: Skipping disconnect of
/ubloxqmi_0/context1, network is connecting.
Aug 01 09:34:11 connmand[181]: ipconfig state 2 ipconfig method 1
Aug 01 09:34:11 connmand[181]: Failed to change property:
/ubloxqmi_0/context1 org.ofono.ConnectionContext.Active:
org.ofono.Error.Failed Operation failed
Aug 01 09:34:11 connmand[181]: ipconfig state 7 ipconfig method 1
Aug 01 09:34:11 connmand[181]: Skipping disconnect of
/ubloxqmi_0/context1, network is connecting.
Aug 01 09:34:11 connmand[181]: ipconfig state 2 ipconfig method 1
Aug 01 09:34:11 connmand[181]: Failed to change property:
/ubloxqmi_0/context1 org.ofono.ConnectionContext.Active:
org.ofono.Error.Failed Operation failed
Aug 01 09:34:11 connmand[181]: ipconfig state 7 ipconfig method 1
Aug 01 09:34:11 connmand[181]: Skipping disconnect of
/ubloxqmi_0/context1, network is connecting.
Aug 01 09:34:11 connmand[181]: ipconfig state 2 ipconfig method 1
Aug 01 09:34:11 connmand[181]: Failed to change property:
/ubloxqmi_0/context1 org.ofono.ConnectionContext.Active:
org.ofono.Error.Failed Operation failed
-------
Thank you.
Kind regards,
- jupiter
^ permalink raw reply [flat|nested] 28+ messages in thread* Re: Unsalble cellular connection 2019-08-01 11:01 JH @ 2019-08-01 18:16 ` Giacinto Cifelli 2019-08-02 10:46 ` JH 0 siblings, 1 reply; 28+ messages in thread From: Giacinto Cifelli @ 2019-08-01 18:16 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 4317 bytes --] Hi jupiter, On Thu, Aug 1, 2019 at 1:01 PM JH <jupiter.hce@gmail.com> wrote: > > Hi, > > I have a device connect to 4G LTE, it was in good connection status on > start up, after a couple of hours, it dropped LTE connection, the > ofono did not show any errors, but connman had lots of error messages > at following, could any one help to explain what could be the problem? > Could it be ofono issue or connman issue? The device has small flash > size which don't have enough space to debug tools. > > # journalctl -u ofono > -- Logs begin at Fri 2019-07-05 05:07:42 UTC, end at Thu 2019-08-01 10:42:49 UT- > Aug 01 07:49:47 systemd[1]: Starting Telephony service... > Aug 01 07:49:48 ofonod[188]: oFono version 1.24 > Aug 01 07:49:48 systemd[1]: Started Telephony service. > Aug 01 07:49:53 ofonod[188]: Interface org.ofono.AllowedAccessPoints not t > Aug 01 07:49:57 ofonod[188]: LTE attach IP type: 0 > Aug 01 08:09:39 ofonod[188]: LTE attach IP type: 0 > > # journalctl -u connman > ......... > Aug 01 08:09:39 connmand[181]: Skipping disconnect of > /ubloxqmi_0/context1, network is connecting. > Aug 01 08:09:39 connmand[181]: ipconfig state 2 ipconfig method 1 > Aug 01 08:09:39 connmand[181]: wwan0 {RX} 45 packets 7963 bytes > Aug 01 08:09:39 connmand[181]: wwan0 {TX} 56 packets 4730 bytes > Aug 01 08:09:39 connmand[181]: wwan0 {update} flags 69841 <UP,RUNNING,LOWER_UP> > Aug 01 08:09:39 connmand[181]: wwan0 {newlink} index 4 address > 00:00:00:00:00:00 mtu 1500 > Aug 01 08:09:39 connmand[181]: wwan0 {newlink} index 4 operstate 0 <UNKNOWN> > Aug 01 08:09:39 connmand[181]: ipconfig state 3 ipconfig method 1 > Aug 01 08:09:39 connmand[181]: wwan0 {add} address 10.114.23.145/30 > label wwan0 family 2 > Aug 01 08:09:39 connmand[181]: wwan0 {add} route 10.114.23.144 gw > 0.0.0.0 scope 253 <LINK> > Aug 01 08:09:39 connmand[181]: wwan0 {add} route 10.114.23.146 gw > 0.0.0.0 scope 253 <LINK> > Aug 01 08:09:39 connmand[181]: wwan0 {add} route 10.4.58.204 gw > 10.114.23.146 scope 0 <UNIVERSE> > Aug 01 08:09:39 connmand[181]: wwan0 {add} route 0.0.0.0 gw > 10.114.23.146 scope 0 <UNIVERSE> > Aug 01 08:09:45 connmand[181]: Online check failed for 0xa71cf8 Telstra > Aug 01 09:34:10 connmand[181]: wwan0 {RX} 140 packets 15185 bytes > Aug 01 09:34:10 connmand[181]: wwan0 {TX} 158 packets 12440 bytes > Aug 01 09:34:10 connmand[181]: wwan0 {update} flags 4240 <DOWN> > Aug 01 09:34:11 connmand[181]: wwan0 {newlink} index 4 address > 00:00:00:00:00:00 mtu 1500 > Aug 01 09:34:11 connmand[181]: wwan0 {newlink} index 4 operstate 2 <DOWN> > Aug 01 09:34:11 connmand[181]: Time request for server 10.114.23.146 > failed (101/Network is unreachable) > Aug 01 09:34:11 connmand[181]: wwan0 {del} address 10.114.23.145/30 label wwan0 > Aug 01 09:34:11 connmand[181]: Skipping disconnect of > /ubloxqmi_0/context1, network is connecting. > Aug 01 09:34:11 connmand[181]: ipconfig state 2 ipconfig method 1 > Aug 01 09:34:11 connmand[181]: Failed to change property: > /ubloxqmi_0/context1 org.ofono.ConnectionContext.Active: > org.ofono.Error.Failed Operation failed > Aug 01 09:34:11 connmand[181]: ipconfig state 7 ipconfig method 1 > Aug 01 09:34:11 connmand[181]: Skipping disconnect of > /ubloxqmi_0/context1, network is connecting. > Aug 01 09:34:11 connmand[181]: ipconfig state 2 ipconfig method 1 > Aug 01 09:34:11 connmand[181]: Failed to change property: > /ubloxqmi_0/context1 org.ofono.ConnectionContext.Active: > org.ofono.Error.Failed Operation failed > Aug 01 09:34:11 connmand[181]: ipconfig state 7 ipconfig method 1 > Aug 01 09:34:11 connmand[181]: Skipping disconnect of > /ubloxqmi_0/context1, network is connecting. > Aug 01 09:34:11 connmand[181]: ipconfig state 2 ipconfig method 1 > Aug 01 09:34:11 connmand[181]: Failed to change property: > /ubloxqmi_0/context1 org.ofono.ConnectionContext.Active: > org.ofono.Error.Failed Operation failed most likely the network dropped the context without signaling. What kind of modem is it? And would you know also the chipset? > > ------- > > Thank you. > > Kind regards, > > - jupiter > _______________________________________________ > ofono mailing list > ofono(a)ofono.org > https://lists.ofono.org/mailman/listinfo/ofono Best regards, Giacinto ^ permalink raw reply [flat|nested] 28+ messages in thread
* Re: Unsalble cellular connection 2019-08-01 18:16 ` Giacinto Cifelli @ 2019-08-02 10:46 ` JH 2019-08-02 17:43 ` Giacinto Cifelli 0 siblings, 1 reply; 28+ messages in thread From: JH @ 2019-08-02 10:46 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 741 bytes --] Hi Giacinto, thanks for your response. On 8/2/19, Giacinto Cifelli <gciofono@gmail.com> wrote: > Hi jupiter, > most likely the network dropped the context without signaling. > What kind of modem is it? And would you know also the chipset? It is uBlox SARA-R4 chipset, did you mean it could be caused by weak LTE signalling level? It is a prototype device, the hardware was designed by an contractor. Any simple way to show LTE signalling level in connman or ofono log files? The trouble is it connected well at startup, then dropped it, it is hard to convince the hardware contractor it is hardware problem unless I have strong evidence that is not the software problem. Thank you very much. Kind regards, - jupiter ^ permalink raw reply [flat|nested] 28+ messages in thread
* Re: Unsalble cellular connection 2019-08-02 10:46 ` JH @ 2019-08-02 17:43 ` Giacinto Cifelli 2019-08-07 10:27 ` JH 0 siblings, 1 reply; 28+ messages in thread From: Giacinto Cifelli @ 2019-08-02 17:43 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 1526 bytes --] Hi jupiter, On Fri, Aug 2, 2019 at 12:46 PM JH <jupiter.hce@gmail.com> wrote: > > Hi Giacinto, thanks for your response. > > On 8/2/19, Giacinto Cifelli <gciofono@gmail.com> wrote: > > Hi jupiter, > > most likely the network dropped the context without signaling. > > What kind of modem is it? And would you know also the chipset? > > It is uBlox SARA-R4 chipset, not sur whether uBlox did this chipset. > did you mean it could be caused by weak > LTE signalling level? It is a prototype device, the hardware was > designed by an contractor. Any simple way to show LTE signalling level > in connman or ofono log files? This signal level is output periodically by ofono in a signal. You can try to catch all ofono signals (these are dbus events, not to be confused with signal level and network signaling) with dbus-monitor. But I think the signal is ok. Only the network disables the PDP context. maybe without informing the modem. This is done by several networks. > The trouble is it connected well at > startup, then dropped it, it is hard to convince the hardware > contractor it is hardware problem unless I have strong evidence that > is not the software problem. Ask uBlox how to capture a protocol stack trace, and if it is feasible for your application, do it and have it analyzed by uBlox. Are you on GSM, on LTE catM or on LTE NB-IOT when this happens? On which network operator and country? > > Thank you very much. > > Kind regards, > > - jupiter BR, Giacinto ^ permalink raw reply [flat|nested] 28+ messages in thread
* Re: Unsalble cellular connection 2019-08-02 17:43 ` Giacinto Cifelli @ 2019-08-07 10:27 ` JH 2019-08-09 3:59 ` Giacinto Cifelli 0 siblings, 1 reply; 28+ messages in thread From: JH @ 2019-08-07 10:27 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 1141 bytes --] Hi Giacinto, Just got response from the hardware contractor. On 8/3/19, Giacinto Cifelli <gciofono@gmail.com> wrote: > Hi jupiter, > This signal level is output periodically by ofono in a signal. > You can try to catch all ofono signals (these are dbus events, not to > be confused with signal level and network signaling) with > dbus-monitor. > But I think the signal is ok. > Only the network disables the PDP context. maybe without informing the > modem. > This is done by several networks. > >> The trouble is it connected well at >> startup, then dropped it, it is hard to convince the hardware >> contractor it is hardware problem unless I have strong evidence that >> is not the software problem. > > Ask uBlox how to capture a protocol stack trace, and if it is feasible > for your application, do it and have it analyzed by uBlox. > > Are you on GSM, on LTE catM or on LTE NB-IOT when this happens? On > which network operator and country? It is LTE Cat-M1, the operator is Telstra in Australia. I will be very interested in finding out what is going on. Thank you. Kind regards, - jupiter ^ permalink raw reply [flat|nested] 28+ messages in thread
* Re: Unsalble cellular connection 2019-08-07 10:27 ` JH @ 2019-08-09 3:59 ` Giacinto Cifelli 2019-08-09 12:56 ` JH 0 siblings, 1 reply; 28+ messages in thread From: Giacinto Cifelli @ 2019-08-09 3:59 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 1408 bytes --] Hi, On Wed, Aug 7, 2019 at 12:27 PM JH <jupiter.hce@gmail.com> wrote: > > Hi Giacinto, > > Just got response from the hardware contractor. > > On 8/3/19, Giacinto Cifelli <gciofono@gmail.com> wrote: > > Hi jupiter, > > > This signal level is output periodically by ofono in a signal. > > You can try to catch all ofono signals (these are dbus events, not to > > be confused with signal level and network signaling) with > > dbus-monitor. > > But I think the signal is ok. > > Only the network disables the PDP context. maybe without informing the > > modem. > > This is done by several networks. > > > >> The trouble is it connected well at > >> startup, then dropped it, it is hard to convince the hardware > >> contractor it is hardware problem unless I have strong evidence that > >> is not the software problem. > > > > Ask uBlox how to capture a protocol stack trace, and if it is feasible > > for your application, do it and have it analyzed by uBlox. > > > > Are you on GSM, on LTE catM or on LTE NB-IOT when this happens? On > > which network operator and country? > > It is LTE Cat-M1, the operator is Telstra in Australia. I will be very > interested in finding out what is going on. you need stack traces. Most likely the chipset you are using is the MDM9205, so the trace will be QXDM. > > Thank you. > > Kind regards, > > - jupiter BR, Giacinto ^ permalink raw reply [flat|nested] 28+ messages in thread
* Re: Unsalble cellular connection 2019-08-09 3:59 ` Giacinto Cifelli @ 2019-08-09 12:56 ` JH 2019-08-11 11:57 ` JH 0 siblings, 1 reply; 28+ messages in thread From: JH @ 2019-08-09 12:56 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 1198 bytes --] Hi Giacinto, I tried to run openwrt on my embedded system, it got netifd daemon to manage the LTE modem, and started udhcpc -p /var/run/udhcpc-wwan0.pid -s /lib/netifd, that problem has gone away. Now I am really worried, if the problem of lost LTE network IP address only happened in connman not in openwrt, it will unlikely be the carry network and modem issues, could it be because that openwrt used udhcpc to refresh the IP address? How does the connman manage the dhcp for LTE IP address? Thank you. Kind regards, - jh On 8/9/19, Giacinto Cifelli <gciofono@gmail.com> wrote: >> > Ask uBlox how to capture a protocol stack trace, and if it is feasible >> > for your application, do it and have it analyzed by uBlox. >> > >> > Are you on GSM, on LTE catM or on LTE NB-IOT when this happens? On >> > which network operator and country? >> >> It is LTE Cat-M1, the operator is Telstra in Australia. I will be very >> interested in finding out what is going on. > > you need stack traces. > Most likely the chipset you are using is the MDM9205, so the trace will be > QXDM. > >> >> Thank you. >> >> Kind regards, >> >> - jupiter > > BR, > Giacinto > ^ permalink raw reply [flat|nested] 28+ messages in thread
* Re: Unsalble cellular connection 2019-08-09 12:56 ` JH @ 2019-08-11 11:57 ` JH 2019-08-11 13:37 ` Giacinto Cifelli 0 siblings, 1 reply; 28+ messages in thread From: JH @ 2019-08-11 11:57 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 3225 bytes --] More observation about the network connection, the device has two network interfaces, WiFi mlan0 and LTE wwan0, I think that problem is likely in connman, not in ofono as in some stage, the wifi IP address lost as well, but it came back. Why connmand contently calling to add and to del both mlan0 and wwan0 in route table? How does the connman manage the route, dhcp to refresh interface IP address? Aug 11 08:01:43 connmand[204]: mlan0 {add} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 08:01:44 connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 08:01:44 connmand[204]: mlan0 {del} route 0.0.0.0 gw 192.168.0.1 scope 0 <UNIVERSE> Aug 11 08:01:44 connmand[204]: wwan0 {add} route 0.0.0.0 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 08:01:44 connmand[204]: wwan0 {add} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 08:01:45 connmand[204]: wwan0 {del} route 212.227.81.55 gw 10.116.108.45 scope 0 <UNIVERSE> Aug 11 08:02:48 connmand[204]: wwan0 {RX} 1365 packets 142181 bytes Aug 11 08:02:49 connmand[204]: wwan0 {TX} 1672 packets 221297 bytes Aug 11 08:02:49 connmand[204]: wwan0 {update} flags 4240 <DOWN> Aug 11 08:02:49 connmand[204]: wwan0 {newlink} index 4 address 00:00:00:00:00:00 mtu 1500 Aug 11 08:02:49 connmand[204]: wwan0 {newlink} index 4 operstate 2 <DOWN> Aug 11 08:02:49 connmand[204]: (null) {del} address 10.116.108.44/29 label wwan0 Aug 11 08:02:49 connmand[204]: wwan0 {dellink} index 4 operstate 2 <DOWN> Aug 11 08:02:49 connmand[204]: (null) {RX} 1365 packets 142181 bytes Aug 11 08:02:49 connmand[204]: (null) {TX} 1672 packets 221297 bytes Aug 11 08:02:49 connmand[204]: (null) {remove} index 4 Aug 11 08:02:49 connmand[204]: Remove interface (null) [ cellular ] Aug 11 08:02:49 connmand[204]: Removing default gateway route failed (No such device) Thank you. Kind regards, - jh On 8/9/19, JH <jupiter.hce@gmail.com> wrote: > Hi Giacinto, > > I tried to run openwrt on my embedded system, it got netifd daemon to > manage the LTE modem, and started udhcpc -p /var/run/udhcpc-wwan0.pid > -s /lib/netifd, that problem has gone away. > > Now I am really worried, if the problem of lost LTE network IP address > only happened in connman not in openwrt, it will unlikely be the carry > network and modem issues, could it be because that openwrt used udhcpc > to refresh the IP address? How does the connman manage the dhcp for > LTE IP address? > > Thank you. > > Kind regards, > > - jh > > On 8/9/19, Giacinto Cifelli <gciofono@gmail.com> wrote: >>> > Ask uBlox how to capture a protocol stack trace, and if it is feasible >>> > for your application, do it and have it analyzed by uBlox. >>> > >>> > Are you on GSM, on LTE catM or on LTE NB-IOT when this happens? On >>> > which network operator and country? >>> >>> It is LTE Cat-M1, the operator is Telstra in Australia. I will be very >>> interested in finding out what is going on. >> >> you need stack traces. >> Most likely the chipset you are using is the MDM9205, so the trace will >> be >> QXDM. >> >>> >>> Thank you. >>> >>> Kind regards, >>> >>> - jupiter >> >> BR, >> Giacinto >> > ^ permalink raw reply [flat|nested] 28+ messages in thread
* Re: Unsalble cellular connection 2019-08-11 11:57 ` JH @ 2019-08-11 13:37 ` Giacinto Cifelli 2019-08-12 6:54 ` JH 0 siblings, 1 reply; 28+ messages in thread From: Giacinto Cifelli @ 2019-08-11 13:37 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 846 bytes --] hi, On Sun, Aug 11, 2019 at 1:57 PM JH <jupiter.hce@gmail.com> wrote: > > More observation about the network connection, the device has two > network interfaces, WiFi mlan0 and LTE wwan0, I think that problem is > likely in connman, not in ofono as in some stage, the wifi IP address > lost as well, but it came back. > > Why connmand contently calling to add and to del both mlan0 and wwan0 > in route table? How does the connman manage the route, dhcp to refresh > interface IP address? can you check with the ofono script test/list-contexts if the method is static or dhcp? I believe this can be the problem: if ofono managed to get an IP address, likely with at+cgpaddr and/or at+cgcontrdp, then it passes it to connman, and then it is set on the interface... static, with no lease expiration. best regards, Giacinto ^ permalink raw reply [flat|nested] 28+ messages in thread
* Re: Unsalble cellular connection 2019-08-11 13:37 ` Giacinto Cifelli @ 2019-08-12 6:54 ` JH 2019-08-12 22:09 ` JH 0 siblings, 1 reply; 28+ messages in thread From: JH @ 2019-08-12 6:54 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 1280 bytes --] Hi Giacinto, On 8/11/19, Giacinto Cifelli <gciofono@gmail.com> wrote: > can you check with the ofono script test/list-contexts if the method > is static or dhcp? # ofono/test/list-contexts [ /ubloxqmi_0 ] [ /ubloxqmi_0/context1 ] Name = Internet Type = internet AuthenticationMethod = chap Settings = { Method=static Gateway=10.116.103.22 Netmask=255.255.255.25} Username = AccessPointName = telstra.m2m Password = Protocol = ip IPv6.Settings = { } Active = 1 Looks like it is static, how can change it to a correct one (dynamic >)? Or any workarounds? > I believe this can be the problem: if ofono managed to get an IP > address, likely with at+cgpaddr and/or at+cgcontrdp, > then it passes it to connman, and then it is set on the interface... > static, with no lease expiration. There are two devices for the SARA-R4 modem, /dev/ttyUSB0 is used for QMI which is currently using as default protocol. /dev/ttyUSB1 is for AT, let me know if you like to check AT command, I have never tried to write / read AT command, are the following commands correct? echo "at+cgpaddr" > /dev/ttyUSB1 cat < /dev/ttyUSB1 Thank you very much Giacinto. -- jupiter ^ permalink raw reply [flat|nested] 28+ messages in thread
* Re: Unsalble cellular connection 2019-08-12 6:54 ` JH @ 2019-08-12 22:09 ` JH 2019-08-13 6:42 ` Jonas Bonn 0 siblings, 1 reply; 28+ messages in thread From: JH @ 2019-08-12 22:09 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 1492 bytes --] Hi Jonas, Do you have any comments about it? Thank you. Kind regards, - jupiter On 8/12/19, JH <jupiter.hce@gmail.com> wrote: > Hi Giacinto, > > On 8/11/19, Giacinto Cifelli <gciofono@gmail.com> wrote: > >> can you check with the ofono script test/list-contexts if the method >> is static or dhcp? > > # ofono/test/list-contexts > [ /ubloxqmi_0 ] > [ /ubloxqmi_0/context1 ] > Name = Internet > Type = internet > AuthenticationMethod = chap > Settings = { Method=static Gateway=10.116.103.22 > Netmask=255.255.255.25} > Username = > AccessPointName = telstra.m2m > Password = > Protocol = ip > IPv6.Settings = { } > Active = 1 > > Looks like it is static, how can change it to a correct one (dynamic >>)? Or any workarounds? > >> I believe this can be the problem: if ofono managed to get an IP >> address, likely with at+cgpaddr and/or at+cgcontrdp, >> then it passes it to connman, and then it is set on the interface... >> static, with no lease expiration. > > There are two devices for the SARA-R4 modem, /dev/ttyUSB0 is used for > QMI which is currently using as default protocol. /dev/ttyUSB1 is for > AT, let me know if you like to check AT command, I have never tried to > write / read AT command, are the following commands correct? > > echo "at+cgpaddr" > /dev/ttyUSB1 > cat < /dev/ttyUSB1 > > Thank you very much Giacinto. > > -- jupiter > ^ permalink raw reply [flat|nested] 28+ messages in thread
* Re: Unsalble cellular connection 2019-08-12 22:09 ` JH @ 2019-08-13 6:42 ` Jonas Bonn 0 siblings, 0 replies; 28+ messages in thread From: Jonas Bonn @ 2019-08-13 6:42 UTC (permalink / raw) To: ofono [-- Attachment #1: Type: text/plain, Size: 2896 bytes --] Hi JH, On 13/08/2019 00:09, JH wrote: > Hi Jonas, > > Do you have any comments about it? Sure... there's not much to go on in the logs you've posted, just an assertion that the LTE connection was silently dropped. It would be better if you could show the behaviour with more complete debug output: ofonod -d The issue could be (perhaps) that there's a QMI message that ofono doesn't handle and is silently ignoring... dumping the QMI communication might useful: OFONO_QMI_DEBUG=1 ofonod -d > > Thank you. > > Kind regards, > > - jupiter > > On 8/12/19, JH <jupiter.hce@gmail.com> wrote: >> Hi Giacinto, >> >> On 8/11/19, Giacinto Cifelli <gciofono@gmail.com> wrote: >> >>> can you check with the ofono script test/list-contexts if the method >>> is static or dhcp? >> >> # ofono/test/list-contexts >> [ /ubloxqmi_0 ] >> [ /ubloxqmi_0/context1 ] >> Name = Internet >> Type = internet >> AuthenticationMethod = chap >> Settings = { Method=static Gateway=10.116.103.22 >> Netmask=255.255.255.25} No Address? No Interface? Running ofono with debug output will probably shed some light on what's going on here. >> Username = >> AccessPointName = telstra.m2m >> Password = >> Protocol = ip >> IPv6.Settings = { } >> Active = 1 >> >> Looks like it is static, how can change it to a correct one (dynamic >>> )? Or any workarounds? static is correct. ofono configures the local network interface appropriately for the established context. Given that ofono isn't reporting either an address nor interface above, I wonder what the network interface has been configured to. What do 'ip link' and 'ip addr' show? >> >>> I believe this can be the problem: if ofono managed to get an IP >>> address, likely with at+cgpaddr and/or at+cgcontrdp, >>> then it passes it to connman, and then it is set on the interface... >>> static, with no lease expiration. I don't think the SARA R4 support DHCP... correct me if I'm wrong. >> >> There are two devices for the SARA-R4 modem, /dev/ttyUSB0 is used for >> QMI which is currently using as default protocol. /dev/ttyUSB1 is for >> AT, No, the QMI device is another USB endpoint that presents interfaces in two separate Linux subsystems: one network device and one qmimisc device. The ttyUSB devices are for AT functionality which you won't be using if you are using the QMI channel. let me know if you like to check AT command, I have never tried to >> write / read AT command, are the following commands correct? >> >> echo "at+cgpaddr" > /dev/ttyUSB1 >> cat < /dev/ttyUSB1 Try using minicom or something similar if you want to play with AT commands directly. /Jonas >> >> Thank you very much Giacinto. >> >> -- jupiter >> ^ permalink raw reply [flat|nested] 28+ messages in thread
end of thread, other threads:[~2019-08-19 14:18 UTC | newest]
Thread overview: 28+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
[not found] <CAOf5uw=2U6MkcKP8OzWNyzwvxjAvYLdXuDASFVEjnWvMQ0fjHw@mail.gmail.com>
2019-08-19 1:51 ` Unsalble cellular connection JH
2019-08-19 5:38 ` Jonas Bonn
2019-08-19 14:18 ` JH
[not found] <CAOf5uw=fQe4cuTfdciqW3hmXHXv-tY2UYd4aLfMVxF5Lx65jbw@mail.gmail.com>
2019-08-19 8:17 ` Jonas Bonn
[not found] <CAOf5uw=6hQkfhAt=OWH+mim30NyOHU6Z8GVMJ6yKCEf=1NFw8w@mail.gmail.com>
2019-08-19 7:50 ` Jonas Bonn
2019-08-19 7:56 ` Jonas Bonn
[not found] <CAA=hcWSVcULFW4jo5q9RsxW4igozgM99oJN6KoZ8UaSLdLhD7g@mail.gmail.com>
2019-08-13 15:00 ` Jonas Bonn
2019-08-14 11:11 ` JH
2019-08-14 13:00 ` Jonas Bonn
2019-08-15 11:33 ` Daniel Wagner
2019-08-15 12:45 ` JH
2019-08-15 14:58 ` Daniel Wagner
2019-08-17 11:53 ` JH
2019-08-17 11:55 ` JH
2019-08-17 14:09 ` Jonas Bonn
2019-08-17 22:29 ` JH
2019-08-01 11:01 JH
2019-08-01 18:16 ` Giacinto Cifelli
2019-08-02 10:46 ` JH
2019-08-02 17:43 ` Giacinto Cifelli
2019-08-07 10:27 ` JH
2019-08-09 3:59 ` Giacinto Cifelli
2019-08-09 12:56 ` JH
2019-08-11 11:57 ` JH
2019-08-11 13:37 ` Giacinto Cifelli
2019-08-12 6:54 ` JH
2019-08-12 22:09 ` JH
2019-08-13 6:42 ` Jonas Bonn
This is an external index of several public inboxes, see mirroring instructions on how to clone and mirror all data and code used by this external index.