Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Can communicate with modem via USB but cannot get connection #7

Open
DDvO opened this issue Oct 19, 2019 · 20 comments
Open

Can communicate with modem via USB but cannot get connection #7

DDvO opened this issue Oct 19, 2019 · 20 comments

Comments

@DDvO
Copy link

DDvO commented Oct 19, 2019

Thanks again @abrasive for your great hack to switch the modem to USB mode!

In my case the modem does respond properly to AT commands.
BTW, do I need the command at+gtusbmode=7 you gave? At least it worked.

Yet for some reason the ModemManager still cannot use the modem properly:
nmcli connection up UMTS (using my connection UMTS) yields

Error: Connection activation failed: The base network connection was interrupted

and on /var/log/messages I obtain

Oct 19 13:14:06 tpx390 NetworkManager[740]: <info>  [1571483646.4585] modem["cdc-wdm0"]: modem state changed, 'disabled' --> 'enabling' (reason: user-requested)
Oct 19 13:14:06 tpx390 NetworkManager[740]: <info>  [1571483646.5789] modem["cdc-wdm0"]: modem state changed, 'enabling' --> 'disabled' (reason: unknown)

The output of mmcli -m 0 is

  --------------------------------
  General  |            dbus path: /org/freedesktop/ModemManager1/Modem/0
           |            device id: 540a42c89ae64dddcf63cad03e99d042bbf306b1
  --------------------------------
  Hardware |         manufacturer: Fibocom
           |                model: MBIM + 3 CDC-ACM
           |             revision: 18500.5001.03.01.20.85
           |         h/w revision: V1.0.4
           |            supported: gsm-umts, lte
           |              current: gsm-umts, lte
           |         equipment id: 015184009731485
  --------------------------------
  System   |               device: /sys/devices/pci0000:00/0000:00:14.0/usb1/1-7
           |              drivers: cdc_acm, cdc_mbim
           |               plugin: Fibocom
           |         primary port: cdc-wdm0
           |                ports: cdc-wdm0 (mbim), ttyACM1 (unknown), wwp0s20f0u7 (net), 
           |                       ttyACM2 (at)
  --------------------------------
  Status   |       unlock retries: sim-pin2 (3)
           |                state: disabled
           |          power state: low
           |       signal quality: 0% (cached)
  --------------------------------
  Modes    |            supported: allowed: 3g; preferred: none
           |                       allowed: 4g; preferred: none
           |                       allowed: 3g, 4g; preferred: none
           |                       allowed: 3g, 4g; preferred: 3g
           |                       allowed: 3g, 4g; preferred: 4g
           |              current: allowed: 3g, 4g; preferred: 4g
  --------------------------------
  Bands    |            supported: utran-1, utran-4, utran-5, utran-8, utran-2, eutran-1, 
           |                       eutran-2, eutran-3, eutran-4, eutran-5, eutran-7, eutran-8, 
           |                       eutran-12, eutran-13, eutran-17, eutran-18, eutran-19, eutran-20, 
           |                       eutran-26, eutran-28, eutran-29, eutran-30, eutran-41, eutran-66
           |              current: utran-1, utran-4, utran-5, utran-8, utran-2, eutran-1, 
           |                       eutran-2, eutran-3, eutran-4, eutran-5, eutran-7, eutran-8, 
           |                       eutran-12, eutran-13, eutran-17, eutran-18, eutran-19, eutran-20, 
           |                       eutran-26, eutran-28, eutran-29, eutran-30, eutran-41, eutran-66
  --------------------------------
  IP       |            supported: ipv4, ipv6, ipv4v6
  --------------------------------
  3GPP     |                 imei: 015184009731485
           |        enabled locks: fixed-dialing
  --------------------------------
  3GPP EPS | ue mode of operation: csps-2
  --------------------------------
  SIM      |            dbus path: /org/freedesktop/ModemManager1/SIM/0
@jmbjorndalen
Copy link

I have a similar problem with mine (Thinkad X1 Yoga 3). After running ./xmm2usb, I run the 3 AT commands for MBIM switch (currently it seems to boot back into MBIM mode when I start the computer, so I'm not sure if I need them any more). Then I run the "FCC unlock" at command, but it doesn't appear to change much. I have a very similar picture and output to yours above.

Then I tried the following (I copied the APN from Windows):

sudo  mmcli -m 0 --simple-connect="apn=internet.netcom.no"
error: couldn't connect the modem: 'GDBus.Error:org.freedesktop.libmbim.Error.Status.Busy: Busy'
sudo mmcli -m 0 --enable
error: couldn't enable the modem: 'GDBus.Error:org.freedesktop.libmbim.Error.Status.Busy: Busy'

After doing that, I played with just setting AT+CFUN=1 (which has failed previously with error 4) while writing this message, but now it didn't complain about anything and I could suddenly connect using the standard XFCE menu.

The main difference I can see now from mmcli -m 0 is is:

  --------------------------------
  Status   |       unlock retries: sim-pin2 (3)
           |                state: registered
           |          power state: on
           |          access tech: lte
           |       signal quality: 38% (cached)
....
  --------------------------------
  3GPP     |                 imei: [removed]
           |        enabled locks: fixed-dialing
           |          operator id: 24202
           |        operator name: Telia N
           |         registration: home

I'll try a few more things to see if I can make a reproducible sequence of actions.

Thanks to @abrasive for figuring this out and sharing with the rest of us!

@DDvO
Copy link
Author

DDvO commented Oct 19, 2019

I get essentially the same output.
The command at+cfun=1 succeeded for me as well, but was not sufficient.
I do not know if this is an issue with the modem or with my connection (or system) configuration.

mmcli -m 0 -e yields:

error: couldn't enable the modem: 'GDBus.Error:org.freedesktop.libmbim.Error.Status.Busy: Busy'

and var/log/syslog contains:

Oct 19 14:30:00 tpx390 ModemManager[2355]: <info>  Modem /org/freedesktop/ModemManager1/Modem/0: state changed (disabled -> enabling)
Oct 19 14:30:00 tpx390 NetworkManager[740]: <info>  [1571488200.7814] modem["cdc-wdm0"]: modem state changed, 'disabled' --> 'enabling' (reason: user-requested)
Oct 19 14:30:00 tpx390 ModemManager[2355]: <info>  Modem /org/freedesktop/ModemManager1/Modem/0: state changed (enabling -> disabled)
Oct 19 14:30:00 tpx390 NetworkManager[740]: <info>  [1571488200.9038] modem["cdc-wdm0"]: modem state changed, 'enabling' --> 'disabled' (reason: unknown)

@jmbjorndalen
Copy link

jmbjorndalen commented Oct 19, 2019

New experiment. I tried resetting the modem with xmm2usb and with a complete powerdown and boot. Both cases worked. The key difference was AT+CFUN=1 to switch the modem from flight mode (4) to on (mode=1).

The complete sequence was:

  • xmm2usb
  • AT+CFUN?
    => +CFUN: 4,0
  • AT+GTUSBMODE?
    => +GTUSBMODE: 7
  • at@nvm:fix_cat_fcclock.fcclock_mode=0
  • AT+CFUN=1
  • AT+CFUN?
    => +CFUN: 1,0

I now get an ip address and route from the modem.

A couple of changes from the README:

  • I made a quick python-program that uses atinout (http://atinout.sourceforge.net/) to run the AT commands (for some reason, I had issues with pySerial) for experimenting with the commands.
  • I also installed the acpi-call-dkms package instead of the source distribution (I'm running Ubuntu 19.04).

@DDvO
Copy link
Author

DDvO commented Oct 19, 2019

Thanks @jmbjorndalen
Due to the additional commmand at@nvm:fix_cat_fcclock.fcclock_mode=0 you mentioned I've been able to enable the moden, so one big step further.

Yet nmcli conn up UMTS failed with

Error: Connection activation failed: Network registration timed out

Maybe there is an issue with the SIM card, which I did insert, according to /var/log/daemon.log`:

Oct 19 20:03:54 tpx390 systemd[1]: Started Modem Manager.
Oct 19 20:03:56 tpx390 ModemManager[5560]: opening device...
Oct 19 20:03:56 tpx390 ModemManager[5560]: cannot connect to proxy: Could not connect: Connection refused
Oct 19 20:03:56 tpx390 ModemManager[5560]: spawning new mbim-proxy (try 1)...
Oct 19 20:03:56 tpx390 ModemManager[5560]: [/dev/cdc-wdm0] Read max control message size from descriptors file: 512
Oct 19 20:03:56 tpx390 ModemManager[5560]: [/dev/cdc-wdm0] channel destroyed
Oct 19 20:03:57 tpx390 ModemManager[5560]: <info>  Couldn't check support for device '/sys/devices/pci0000:00/0000:00:14.3': not supported by any plugin
Oct 19 20:03:57 tpx390 ModemManager[5560]: <info>  Couldn't check support for device '/sys/devices/pci0000:00/0000:00:1f.6': not supported by any plugin
Oct 19 20:04:05 tpx390 ModemManager[5560]: <info>  [device /sys/devices/pci0000:00/0000:00:14.0/usb1/1-7] creating modem with plugin 'Fibocom' and '5' ports
Oct 19 20:04:05 tpx390 ModemManager[5560]: <warn>  Could not grab port (tty/ttyACM2): 'Cannot add port 'tty/ttyACM2', unhandled serial type'
Oct 19 20:04:05 tpx390 ModemManager[5560]: <warn>  Could not grab port (tty/ttyACM0): 'Cannot add port 'tty/ttyACM0', unhandled serial type'
Oct 19 20:04:05 tpx390 ModemManager[5560]: <info>  Modem for device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7' successfully created
Oct 19 20:04:05 tpx390 ModemManager[5560]: opening device...
Oct 19 20:04:05 tpx390 ModemManager[5560]: [/dev/cdc-wdm0] Read max control message size from descriptors file: 512
Oct 19 20:04:05 tpx390 ModemManager[5560]: [/dev/cdc-wdm0] Opening device with flags 'version-info, proxy, mbim, expect-indications'...
Oct 19 20:04:05 tpx390 ModemManager[5560]: [/dev/cdc-wdm0] loaded driver of cdc-wdm port: cdc_mbim
Oct 19 20:04:05 tpx390 ModemManager[5560]: [/dev/cdc-wdm0] creating MBIM device...
Oct 19 20:04:05 tpx390 ModemManager[5560]: [/dev/cdc-wdm0] MBIM device created
Oct 19 20:04:05 tpx390 ModemManager[5560]: [/dev/cdc-wdm0] opening MBIM device...
Oct 19 20:04:05 tpx390 ModemManager[5560]: opening device...
Oct 19 20:04:05 tpx390 ModemManager[5560]: [/dev/cdc-wdm0] Read max control message size from descriptors file: 512
Oct 19 20:04:05 tpx390 ModemManager[5560]: [/dev/cdc-wdm0] MBIM device open
Oct 19 20:04:05 tpx390 ModemManager[5560]: [/dev/cdc-wdm0] Checking version info (15 retries)...
Oct 19 20:04:05 tpx390 ModemManager[5560]: [/dev/cdc-wdm0] sending message as MBIM...
Oct 19 20:04:05 tpx390 ModemManager[5560]: <info>  [cdc-wdm0] MBIM device is not QMI capable
Oct 19 20:04:05 tpx390 ModemManager[5560]: [/dev/cdc-wdm0] MBIM device wasn't explicitly closed
Oct 19 20:04:05 tpx390 ModemManager[5560]: [/dev/cdc-wdm0] channel destroyed
Oct 19 20:04:05 tpx390 ModemManager[5560]: <warn>  couldn't load Supported Bands: 'Unsupported'
Oct 19 20:04:17 tpx390 ModemManager[5560]: <warn>  Modem couldn't be initialized: Couldn't check unlock status: Couldn't get SIM lock status after 6 retries
Oct 19 20:04:17 tpx390 ModemManager[5560]: <info>  Modem: state changed (unknown -> failed)
Oct 19 20:04:17 tpx390 ModemManager[5560]: <warn>  Couldn't open ports during Modem SIM hot swap enabling: Couldn't get primary port
Oct 19 20:04:17 tpx390 ModemManager[5560]: <error> SIM is missing and SIM hot swap is configured, but ports are not opened.

@DDvO
Copy link
Author

DDvO commented Oct 20, 2019

I thought that rebooting the system might help to get my SIM card recognized (or whatever the problem is), but it did not.

As one could expect, after the reboot the modem was back to its original state, so I had to re-do

xmm2usb
at+gtusbmode=7
at@nvm:fix_cat_fcclock.fcclock_mode=0
at+cfun=1

yet also this time this was not sufficient.

Via the screen command I can see due to the connection attempts:


+CME ERROR: 30

+CME ERROR: 30

+CME ERROR: 30

+CME ERROR: 30

+CME ERROR: 30

+CME ERROR: 30

+CME ERROR: 30

+CME ERROR: 30

+CME ERROR: 30

and /var/log/daemon.log contains

Oct 20 10:56:18 tpx390 systemd[1]: NetworkManager-dispatcher.service: Succeeded.
Oct 20 10:56:28 tpx390 wpa_supplicant[753]: wlp0s20f3: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-68 noise=9999 txrate=130000
Oct 20 10:56:24 tpx390 systemd[1]: systemd-hostnamed.service: Succeeded.
Oct 20 10:56:24 tpx390 systemd[1]: systemd-fsckd.service: Succeeded.
Oct 20 10:58:05 tpx390 ModemManager[744]: <info>  (tty/ttyACM1): released by device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7'
Oct 20 10:58:05 tpx390 ModemManager[744]: <info>  (tty/ttyACM2): released by device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7'
Oct 20 10:58:05 tpx390 ModemManager[744]: <info>  (tty/ttyACM0): released by device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7'
Oct 20 10:58:05 tpx390 ModemManager[744]: <info>  Couldn't check support for device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7': Operation was cancelled
Oct 20 10:58:05 tpx390 systemd-udevd[1605]: Using default interface naming scheme 'v240'.
Oct 20 10:58:05 tpx390 systemd-udevd[1610]: Using default interface naming scheme 'v240'.
Oct 20 10:58:05 tpx390 systemd-udevd[1611]: Using default interface naming scheme 'v240'.
Oct 20 10:58:05 tpx390 systemd-udevd[1610]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
Oct 20 10:58:05 tpx390 systemd-udevd[1605]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
Oct 20 10:58:05 tpx390 systemd-udevd[1611]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
Oct 20 10:58:06 tpx390 ModemManager[744]: <info>  (tty/ttyACM0): released by device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7'
Oct 20 10:58:06 tpx390 ModemManager[744]: <info>  (tty/ttyACM2): released by device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7'
Oct 20 10:58:06 tpx390 ModemManager[744]: <info>  (tty/ttyACM1): released by device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7'
Oct 20 10:58:06 tpx390 ModemManager[744]: <info>  (net/enx000011121318): released by device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7'
Oct 20 10:58:06 tpx390 ModemManager[744]: <info>  (net/enx000011121314): released by device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7'
Oct 20 10:58:06 tpx390 ModemManager[744]: <info>  (net/enx000011121316): released by device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7'
Oct 20 10:58:06 tpx390 ModemManager[744]: <info>  Couldn't check support for device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7': Operation was cancelled
Oct 20 10:58:06 tpx390 systemd-udevd[1603]: Using default interface naming scheme 'v240'.
Oct 20 10:58:06 tpx390 systemd-udevd[1613]: Using default interface naming scheme 'v240'.
Oct 20 10:58:06 tpx390 systemd-udevd[1602]: Using default interface naming scheme 'v240'.
Oct 20 10:58:06 tpx390 systemd-udevd[1613]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
Oct 20 10:58:06 tpx390 systemd-udevd[1603]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
Oct 20 10:58:06 tpx390 systemd-udevd[1602]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
Oct 20 10:58:06 tpx390 systemd-udevd[1614]: Using default interface naming scheme 'v240'.
Oct 20 10:58:06 tpx390 systemd-udevd[1615]: Using default interface naming scheme 'v240'.
Oct 20 10:58:06 tpx390 systemd-udevd[1608]: Using default interface naming scheme 'v240'.
Oct 20 10:58:06 tpx390 ModemManager[744]: <info>  (tty/ttyACM0): released by device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7'
Oct 20 10:58:06 tpx390 ModemManager[744]: <info>  (tty/ttyACM1): released by device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7'
Oct 20 10:58:06 tpx390 ModemManager[744]: <info>  (tty/ttyACM2): released by device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7'
Oct 20 10:58:06 tpx390 ModemManager[744]: <info>  (net/enx000011121314): released by device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7'
Oct 20 10:58:06 tpx390 ModemManager[744]: <info>  (net/enx000011121316): released by device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7'
Oct 20 10:58:06 tpx390 ModemManager[744]: <info>  (net/enx000011121318): released by device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7'
Oct 20 10:58:06 tpx390 ModemManager[744]: <info>  Couldn't check support for device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7': Operation was cancelled
Oct 20 10:58:07 tpx390 systemd-udevd[1614]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
Oct 20 10:58:07 tpx390 systemd-udevd[1614]: usb0: Failed to rename network interface 10 from 'usb0' to 'enx000011121314': No such device
Oct 20 10:58:07 tpx390 systemd-udevd[1612]: Using default interface naming scheme 'v240'.
Oct 20 10:58:07 tpx390 systemd-udevd[1612]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
Oct 20 10:58:07 tpx390 systemd-udevd[1612]: usb1: Failed to rename network interface 11 from 'usb1' to 'enx000011121316': No such device
Oct 20 10:58:07 tpx390 ModemManager[744]: <info>  (tty/ttyACM1): released by device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7'
Oct 20 10:58:07 tpx390 ModemManager[744]: <info>  (tty/ttyACM2): released by device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7'
Oct 20 10:58:07 tpx390 ModemManager[744]: <info>  (tty/ttyACM0): released by device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7'
Oct 20 10:58:07 tpx390 ModemManager[744]: <info>  (net/usb0): released by device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7'
Oct 20 10:58:07 tpx390 ModemManager[744]: <info>  (net/usb1): released by device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7'
Oct 20 10:58:07 tpx390 ModemManager[744]: <info>  Couldn't check support for device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7': Operation was cancelled
Oct 20 10:58:07 tpx390 systemd-udevd[1610]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
Oct 20 10:58:07 tpx390 systemd-udevd[1614]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
Oct 20 10:58:07 tpx390 systemd-udevd[1605]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
Oct 20 10:58:30 tpx390 ModemManager[744]: <info>  [device /sys/devices/pci0000:00/0000:00:14.0/usb1/1-7] creating modem with plugin 'Generic' and '6' ports
Oct 20 10:58:30 tpx390 ModemManager[744]: <warn>  Could not grab port (tty/ttyACM1): 'Cannot add port 'tty/ttyACM1', unhandled serial type'
Oct 20 10:58:30 tpx390 ModemManager[744]: <info>  Modem for device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-7' successfully created
Oct 20 10:58:31 tpx390 ModemManager[744]: <info>  Modem: state changed (unknown -> disabled)
Oct 20 10:58:31 tpx390 ModemManager[744]: <info>  Modem /org/freedesktop/ModemManager1/Modem/0: state changed (disabled -> enabling)
Oct 20 10:58:31 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 10:58:31 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 10:58:31 tpx390 ModemManager[744]: <info>  Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (unknown -> idle)
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Modem /org/freedesktop/ModemManager1/Modem/0: state changed (enabling -> enabled)
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 10:58:32 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 10:58:36 tpx390 dbus-daemon[1256]: [session uid=1000 pid=1256] Activating service name='org.freedesktop.secrets' requested by ':1.138' (uid=1000 pid=1855 comm="/usr/lib/chromium/chromium --show-component-extens")
Oct 20 10:58:36 tpx390 dbus-daemon[1256]: [session uid=1000 pid=1256] Successfully activated service 'org.freedesktop.secrets'
Oct 20 10:58:36 tpx390 dbus-daemon[1256]: [session uid=1000 pid=1256] Activating service name='org.gnome.keyring.SystemPrompter' requested by ':1.140' (uid=1000 pid=1925 comm="/usr/bin/gnome-keyring-daemon --start --foreground")
Oct 20 10:58:36 tpx390 dbus-daemon[1256]: [session uid=1000 pid=1256] Successfully activated service 'org.gnome.keyring.SystemPrompter'
Oct 20 11:01:14 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 11:01:14 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 11:01:14 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 11:01:27 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 11:01:27 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 11:01:27 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 11:02:12 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 11:02:12 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 11:02:12 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 11:02:12 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 11:02:12 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 11:02:12 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 11:02:12 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 11:02:12 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 11:02:12 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 11:03:14 tpx390 dbus-daemon[742]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.5' (uid=0 pid=743 comm="/usr/sbin/NetworkManager --no-daemon ")
Oct 20 11:03:14 tpx390 systemd[1]: Starting Network Manager Script Dispatcher Service...
Oct 20 11:03:14 tpx390 dbus-daemon[742]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Oct 20 11:03:14 tpx390 systemd[1]: Started Network Manager Script Dispatcher Service.
Oct 20 11:03:14 tpx390 nm-dispatcher: req:1 'down' [ttyACM0]: new request (1 scripts)
Oct 20 11:03:14 tpx390 nm-dispatcher: req:1 'down' [ttyACM0]: start running ordered scripts...
Oct 20 11:03:24 tpx390 systemd[1]: NetworkManager-dispatcher.service: Succeeded.
Oct 20 11:03:31 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 11:03:31 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 11:03:31 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 11:03:31 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 11:03:31 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 11:03:31 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 11:03:31 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 11:03:31 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 11:03:31 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 11:03:32 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 11:03:32 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 11:03:32 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 11:03:32 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 11:03:32 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 11:03:32 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 11:03:39 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 11:03:39 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 11:03:39 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 11:03:39 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 11:03:39 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 11:03:39 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 11:03:48 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 11:03:48 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 11:03:48 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 11:03:48 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 11:03:48 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 11:03:48 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 11:03:48 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 11:03:48 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 11:03:48 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 11:03:48 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 11:03:48 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 11:03:48 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 11:05:12 tpx390 wpa_supplicant[753]: wlp0s20f3: WPA: Group rekeying completed with e0:28:6d:20:17:02 [GTK=CCMP]
Oct 20 11:05:48 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 11:05:48 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 11:05:48 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 11:05:48 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 11:05:48 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 11:05:48 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 11:05:48 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 11:05:48 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 11:05:48 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 11:07:48 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 11:07:48 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 11:07:48 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 11:07:48 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 11:07:48 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 11:07:48 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register
Oct 20 11:07:48 tpx390 ModemManager[744]: <info>  Simple connect started...
Oct 20 11:07:48 tpx390 ModemManager[744]: <info>  Simple connect state (4/8): Wait to get fully enabled
Oct 20 11:07:48 tpx390 ModemManager[744]: <info>  Simple connect state (5/8): Register

@DDvO
Copy link
Author

DDvO commented Oct 20, 2019

After issuing at@store_nvm(fix_cat_fcclock) and rebooting,
there was no need any more to use again

AT+GTUSBMODE=7
at@nvm:fix_cat_fcclock.fcclock_mode=0
AT+CFUN=1

@mmack
Copy link

mmack commented Oct 23, 2019

fun fact: if i wait 20min after issuing this commands suddenly the device comes up and conncects 💃

@jmbjorndalen
Copy link

@DDvO : I haven't had a chance to play with it since the weekend. Have you tried completely powering it off and on again after store_nvm ? I guess it only modifies the fcc lock, so it shouldn't cause it to run into any bios whitelist issues.

Did you get it to connect in the end?

@mem-
Copy link

mem- commented Oct 29, 2019

Hi,

I have a X1 Carbon gen6 and got it (almost) working with AT+CFUN=1 together with the other AT commands.

Then I did: mmcli -m 0 --simple-connect='pin=5555,apn=foo.bar.com'

Now "mmcli -b 0" shows a lot of things including "IPv4 configuration" with IPs but nigher "ip addr" or "ip route" show any information related to the address(es).

Do I have to do some more to actually address active in Linux?
"systemctl status ModemManager.service" says " Simple connect state (8/8): All done"
For now I'm using Wicd, maybe I have to change the name the "Wired interface"?
I'm thinking of switching to networkd and I guess that I then need some file in /etc/systemd/network/ like umts.network or similar.

Regards,
// Mem

@DDvO
Copy link
Author

DDvO commented Nov 2, 2019

After hibernate & resume, the modem disappers.

/dev/ttyACM{0,1,2} are gone,
and ./xmm2usb says:

ERROR: Did not find an XMM7360 modem

Update:
when I then suspend (to RAM) & resume, the modem re-appears :)

BTW, I'm meanwhile using the kernel module variant of @abrasive's script:
https://github.com/juhovh/xmm7360_usb

@DDvO
Copy link
Author

DDvO commented Nov 2, 2019

@DDvO : I haven't had a chance to play with it since the weekend. Have you tried completely powering it off and on again after store_nvm ? I guess it only modifies the fcc lock, so it shouldn't cause it to run into any bios whitelist issues.

After powering off & reboot, the behavior is still as I wrote on Oct 20,
i.e., the values I stored persist:

+GTUSBMODE: 7
+CFUN: 1,0

Did you get it to connect in the end?

No, e.g., on mmcli -m 0 --simple-connect="apn=web.vodafone.de"
I still get immediately:

error: couldn't connect the modem: 'GDBus.Error:org.freedesktop.ModemManager1.Error.MobileEquipment.NetworkTimeout: Network timeout'

which must be somewhat misleading since this happens regardless if a SIM card is inserted (and detected) or not.

@DDvO
Copy link
Author

DDvO commented Nov 2, 2019

Interestingly, lsusb | grep Intel now says

Bus 001 Device 006: ID 8087:0aaa Intel Corp.

i.e. the device ID 8087:095a for the modem, which I got before, has disappeared.
Can anyone explain this?

@DDvO
Copy link
Author

DDvO commented Nov 2, 2019

Meanwhile I'm sure the SIM card is recognized - for instance,
mbimcli -p -d /dev/cdc-wdm0 --query-subscriber-ready-status
yields

[/dev/cdc-wdm0] Subscriber ready status retrieved:
	      Ready state: 'initialized'
	    Subscriber ID: '262026141096513'
	        SIM ICCID: '89492026196025062299'
	       Ready info: 'none'
	Telephone numbers: (0) 'unknown'

Yet mmcli -m 0 --3gpp-scan still yields

error: couldn't scan networks in the modem: 
  'GDBus.Error:org.freedesktop.libmbim.Error.Status.Busy: Busy'

Update: the latter happens also when the modem has been connected via the ModemManager.

@DDvO
Copy link
Author

DDvO commented Nov 3, 2019

After many hours of frustrating trial and error, I was about to replace the modem hardware of the ThinkPad X390 with the one of a ThinkPad Yoga 370: a Sierra Wireless EM7455, which works out of the box.

But then I did a last experiment, which finally gave success:
I hibernated Linux, booted Windows 10 (which I still have on a different partition) and tried the modem there, which worked immediately.
Then I hibernated Windows and resumed Linux. As I wrote above, the modem does not appear after hibernation, but after an additional suspend&resume it re-appears.
The modem was disabled, but this could be fixed using mmcli -m 0 --enable.
Then suddenly mmcli -m 0 --3gpp-scan worked!

Yet still I could not start a connection via mmcli -m 0 --simple-connect="apn=web.vodafone.de" nor mbim-network /dev/cdc-wdm0 start. Then I tried using wvdial, and after a little fiddling with its configuration, it got connected :) Here is my /etc/wvdial.conf`:

[Dialer reset]
Init1 = AT+CFUN=15

[Dialer Defaults]
Modem Type = USB Modem
Modem = /dev/ttyACM0
Baud = 460800
Password = dummy # wvdial requires value
Username = dummy # wvdial requires value
Phone = *99#
Stupid mode = 1 # do not wait for login prompt

It turns out that the ModemManager interferes with wvdial, such that the latter tends to stop with e.g., Modem not responding or ERROR or strange error codes:+CME ERROR: 131 or +CME ERROR: 148 .
When this happens, I stop it using systemctl stop ModemManager and reset the modem, which can be done conveniently using the first section of my wvdial.conf, namely by invoking wvdial reset.
After a few seconds the modem comes up in clean state, and wvdial connects smoothly and consistently.

Just a shame that other, more modern and convenient, higher-level ways of connecting do not (yet) work.

Update:
I don't really understand why, but meanwhile also mbim-network /dev/cdc-wdm0 start works (at least after setting up /etc/mbim-network.conf with a suitable APN entry and PROXY=yes)
and after re-activating the ModemManager also mmcli -m 1 --simple-connect="apn=" and even nmcli conn up UMTS :)

@abrasive
Copy link
Collaborator

abrasive commented Nov 4, 2019

@DDvO It may be that after a hibernate-resume cycle, the power is not properly restored to the card. I had this happen when I booted the laptop without the card present. Does kicking the _RST method manually work at all?

If not, try and find the power off/on ACPI methods, as described in this comment - power cycling the card may be more successful.

@DDvO
Copy link
Author

DDvO commented Nov 6, 2019

Thanks @abrasive for the hint, but /proc/acpi/call does not exist on my (Debian 10) system.

At least in some situations the modem is disabled after resume from hibernation, and then I cannot get a connection even with suspend&resume.
Enabling it manually (mmcli -m 2 --enable) appears to work and my bearer (Vodafone.de LTE) appears in the NetworkManager menu, but is greyed out.
When running mmcli -m 2 --simple-connect="apn=, it claims successfully connected the modem , but I do not really have IP network access.
nmcli con up UMTS funnily says Error: Connection activation failed: No suitable device found for this connection (device cdc-wdm1 not available because device is not available)..
After stopping the ModemManager, wvdial sometimes works fine in these situations, sometimes says Modem not responding.
I believe this remaining issue is due to some higher-level hickup in the system, not at modem (nor its USB connection) level, maybe because /dev/cdc-wdm0 changed to /dev/cdc-wdm0?

@abrasive
Copy link
Collaborator

abrasive commented Nov 6, 2019

Wait, what? The xmm2usb script depends on the acpi_call module, which exposes @/proc/apci/call. So, y'know, it's been there ;-) Try modprobe acpi_call?

@DDvO
Copy link
Author

DDvO commented Nov 6, 2019

Well, it looks like /proc/apci/call is present only after using your script, not when using the kernel module based variant derived from it: https://github.com/juhovh/xmm7360_usb

When I then use your script, /proc/apci/call appears. Both

echo '\_SB.PCI0.RP21.POFF' | sudo tee /proc/acpi/call
echo '\_SB.PCI0.RP21.PON' | sudo tee /proc/acpi/call

do not complain but dmesg contains

[ 1625.464016] acpi_call: Cannot get handle: Error: AE_NOT_FOUND
[ 1628.601051] acpi_call: Cannot get handle: Error: AE_NOT_FOUND

@abrasive
Copy link
Collaborator

abrasive commented Nov 7, 2019

Ah, of course. You might dump your ACPI tables and disassemble them with iasl; then you could poke around under the PCI0.RP21 scope and see what methods you find there.There may be a PXP object or similar that holds the actual power methods.

@pc-rzn
Copy link

pc-rzn commented Mar 28, 2023

AT+CFUN?
at@nvm:fix_cat_fcclock.fcclock_mode?
at@nvm:fix_cat_fcclock.fcclock_mode=0
at@store_nvm(fix_cat_fcclock)
AT+CFUN=1
AT+CFUN?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

6 participants