[Pkg-utopia-maintainers] Bug#773045: modemmanager: Sierra Wireless EM7345 only works until first suspend

Jens Erat jenserat at jenserat.de
Sat Dec 13 15:35:31 UTC 2014


Package: modemmanager
Version: 1.4.0-1
Severity: normal

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Dear Maintainer,

I'm using a Lenovo Thinkpad T440s with built-in LTE card "Sierra Wireless EM7345 4G LTE" (as bundled by Lenovo).

I can connect using network manager, but only when the system was not suspended (or hibernated) in-between. After suspending, I have to reboot; otherwise network manager will show an error message:

> Error: Connection activation failed: Connection 'Vodafone 5GB' is
> not available on the device ttyACM0 at this time.

Disabling/enabling the modem using `mmcli -m [id] -{d, e}` did not resolve the issue.

I observed that `mmcli -L` shows the modem with a different ID after each suspend. Without suspending, the modem has ID 0, after suspending the first time it gets 1 (and increments with each suspend). I'm not sure whether that's expected behavior.

> /org/freedesktop/ModemManager1/Modem/1 [Sierra Wireless Inc.] Sierra Wireless EM7345 4G LTE

When trying to use mmcli to connect, successfull connections are reported, but no interface shows up (while connecting with network manager creates an interface `ppp0`).

    mmcli -m 1 --simple-connect="allow-roaming=no,pin=1337,apn=web.vodafone.de"

I have no experiences with modem manager so far and not totally sure what's expected behavior and what's not, nor what additional information to report. I attached a debug log excerpt from the syslog of a connection attempt _after_ suspending the machine.

Using Windows, the card also works after suspending the machine, so it should not be a hardware issue.

Regards from Lake Constance, Germany,
Jens

- -- System Information:
Debian Release: 8.0
  APT prefers testing
  APT policy: (1000, 'testing'), (750, 'testing'), (500, 'testing-updates'), (50, 'unstable'), (1, 'experimental')
Architecture: amd64 (x86_64)

Kernel: Linux 3.17-1-amd64 (SMP w/4 CPU cores)
Locale: LANG=de_DE.utf8, LC_CTYPE=de_DE.utf8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)

Versions of packages modemmanager depends on:
ii  init-system-helpers    1.22
ii  libc6                  2.19-13
ii  libglib2.0-0           2.42.1-1
ii  libgudev-1.0-0         215-7
ii  libmbim-glib4          1.10.0-2
ii  libmbim-proxy          1.10.0-2
ii  libmm-glib0            1.4.0-1
ii  libpolkit-gobject-1-0  0.105-8
ii  libqmi-glib1           1.10.2-2
ii  libqmi-proxy           1.10.2-2

Versions of packages modemmanager recommends:
ii  usb-modeswitch  2.2.0+repack0-2

modemmanager suggests no packages.

- -- no debconf information

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1

iQIcBAEBAgAGBQJUjFy+AAoJEI545E37G1XpL7kP/3zIqB/LXaWYprtSyB+cERBz
8TsVgKo+VlzJEtqJ+/fgB/qvNDDZbGCQXZv9nG7u8ouhcj7SqLFTeWZJUuqz/mLT
/mbtGEjQ3UbGW56BSNynQqzjyYmHHihU470O7l/tUNGAqpXBH60TWBFgsz+BDSTL
NH/NXZf/1l2DTtPOl1MuXVlY0UDfgmyqbebdgK3+SqECLziIenV/reRMmp+VCqK6
xMEzt2qhQQstkYs3NmmcVkrnLGw7A18q26jckOR/xQJ2WLQn+B3BMXXK17kCsZne
+AUpkcme7OFDDn/HUOpft/r9JbRNFu9u71Ck05UXfxYvFNDD0bfGYcqkMl6ZW4FW
Dsf+PE+ugL4Mn7gkC7GIW0RcDh+dfZX9ib/x/Qhctxj1DwxQ8KlDI2+Ac90wn/16
E0CrzxH35SSHM36V50mtYHzqiq4JQ6sCaSRkzfwG94fJnoFGLabuX3dG2dg3fPTA
mhfkQgPvo8DuE4hWn1mFjKG61LhOczxBQYz3g1O0DG+ru1uZIJjh99+KCSB52bdf
pQc9wB8H8Er+/BuF2efr6dldXk+pOi5Z22wB9ES3veKPOaBeh3sxftZPeUiNw9dU
4Bk5ye/AlVxL9kTc8HepUTwy7TY/zJ2EyV9WHgakR9iGGp41AxCz7ne07blt7Gnw
hwSKKZHAdJNIiYS36KaK
=FGq1
-----END PGP SIGNATURE-----
-------------- next part --------------
Dec 13 16:30:00 t440s ModemManager[756]: <info>  Simple connect started...
Dec 13 16:30:00 t440s ModemManager[756]: <debug>    PIN: 1337
Dec 13 16:30:00 t440s ModemManager[756]: <debug>    Operator ID: unspecified
Dec 13 16:30:00 t440s ModemManager[756]: <debug>    Allowed roaming: no
Dec 13 16:30:00 t440s ModemManager[756]: <debug>    APN: web.vodafone.de
Dec 13 16:30:00 t440s ModemManager[756]: <debug>    IP family: unspecified
Dec 13 16:30:00 t440s ModemManager[756]: <debug>    Allowed authentication: unspecified
Dec 13 16:30:00 t440s ModemManager[756]: <debug>    User: unspecified
Dec 13 16:30:00 t440s ModemManager[756]: <debug>    Password: unspecified
Dec 13 16:30:00 t440s ModemManager[756]: <debug>    Number: unspecified
Dec 13 16:30:00 t440s ModemManager[756]: <info>  Simple connect state (3/8): Enable
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 1 (open)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): running init sequence...
Dec 13 16:30:00 t440s ModemManager[756]: <debug> Flashing primary AT port before enabling...
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): --> 'ATE0<CR>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> loading power state...
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (open)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): --> 'ATV1<CR>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+CMEE=1<CR>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): --> 'ATX4<CR>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT&C1<CR>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+CFUN?<CR>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+CFUN: 1,0<CR><LF><CR><LF>OK<CR><LF>'
Dec 13 16:30:00 t440s ModemManager[756]: Couldn't reload current power state: Failed to parse +CFUN? response '1,0'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> No need to change power state: already in 'on' power state
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 1 (close)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (open)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 3 (open)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+IFC=1,1<CR>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+CME ERROR: 100<CR><LF>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> Got failure code 100: Unknown error
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (close)
Dec 13 16:30:00 t440s ModemManager[756]: <warn>  (ttyACM0) response array is not empty when using cached reply, cleaning up 15 bytes
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 3 (open)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (close)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+CSCS="UCS2"<CR>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 3 (open)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (close)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+CSCS?<CR>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+CSCS: "UCS2"<CR><LF><CR><LF>OK<CR><LF>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 1 (close)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> Modem has 3GPP capabilities, enabling the Modem 3GPP interface...
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) Setting 3GPP unsolicited events handlers
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (open)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+CMER=3,0,0,1<CR>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+CME ERROR: 50<CR><LF>'
Dec 13 16:30:00 t440s ModemManager[756]: Invalid mobile equipment error code: 50
Dec 13 16:30:00 t440s ModemManager[756]: <debug> Got failure code 100: Unknown error
Dec 13 16:30:00 t440s ModemManager[756]: <debug> Couldn't enable event reporting: 'Unknown error'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) setting up 3GPP unsolicited registration messages handlers
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 1 (close)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (open)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+CREG=2<CR>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 3 (open)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (close)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+CGREG=2<CR>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 1 (close)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> Running registration checks (CS: 'yes', PS: 'yes', EPS: 'no')
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (open)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+CREG?<CR>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+CREG: 2,1,"02EA","000079AF",0<CR><LF><CR><LF>OK<CR><LF>'
Dec 13 16:30:00 t440s ModemManager[756]: <info>  Modem /org/freedesktop/ModemManager1/Modem/1: 3GPP Registration state changed (unknown -> registering)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> loading Operator Code...
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 3 (open)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> Modem /org/freedesktop/ModemManager1/Modem/1: access technology changed (unknown -> gsm)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 4 (open)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 3 (close)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+COPS=3,2;+COPS?<CR>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+COPS: 0,2,"00320036003200300032",0<CR><LF><CR><LF>OK<CR><LF>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> loaded Operator Code: 00320036003200300032
Dec 13 16:30:00 t440s ModemManager[756]: <debug> Unexpected MCC/MNC string '00320036003200300032'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> loading Operator Name...
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 4 (open)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 3 (close)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+CGREG?<CR>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+CGREG: 2,1,"02EA","000079AF",0,"02"<CR><LF><CR><LF>OK<CR><LF>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (close)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> Modem has 3GPP/USSD capabilities, enabling the Modem 3GPP/USSD interface...
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) Setting unsolicited result code handlers
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 3 (open)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+COPS=3,0;+COPS?<CR>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+COPS: 0,0,"0056006F006400610066006F006E0065002E00640065",0<CR><LF><CR><LF>OK<CR><LF>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> loaded Operator Name: Vodafone.de
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (close)
Dec 13 16:30:00 t440s ModemManager[756]: <info>  Modem /org/freedesktop/ModemManager1/Modem/1: 3GPP Registration state changed (registering -> home)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 1 (close)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> Modem has location capabilities, enabling the Location interface...
Dec 13 16:30:00 t440s ModemManager[756]: <debug> Need to enable the following location sources: '3gpp-lac-ci'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> Running registration checks (CS: 'yes', PS: 'yes', EPS: 'no')
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (open)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> loading Operator Code...
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 3 (open)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> Modem has messaging capabilities, enabling the Messaging interface...
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 4 (open)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+CREG?<CR>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+CREG: 2,1,"02EA","000079AF",0<CR><LF><CR><LF>OK<CR><LF>'
Dec 13 16:30:00 t440s ModemManager[756]: <info>  Modem /org/freedesktop/ModemManager1/Modem/1: 3GPP location updated (MCC: '0', MNC: '0', Location area code: '2EA', Cell ID: '79AF')
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 5 (open)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 4 (close)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+COPS=3,2;+COPS?<CR>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+COPS: 0,2,"00320036003200300032",0<CR><LF><CR><LF>OK<CR><LF>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> loaded Operator Code: 00320036003200300032
Dec 13 16:30:00 t440s ModemManager[756]: <debug> Unexpected MCC/MNC string '00320036003200300032'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> loading Operator Name...
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 5 (open)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 4 (close)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> Successfully set preferred SMS mode: 'PDU'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 5 (open)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 4 (close)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+CGREG?<CR>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+CGREG: 2,1,"02EA","000079AF",0,"02"<CR><LF><CR><LF>OK<CR><LF>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 3 (close)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+COPS=3,0;+COPS?<CR>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+COPS: 0,0,"0056006F006400610066006F006E0065002E00640065",0<CR><LF><CR><LF>OK<CR><LF>'
Dec 13 16:30:00 t440s ModemManager[756]: <debug> loaded Operator Name: Vodafone.de
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (close)
Dec 13 16:30:00 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+CPMS="","SM","SM"<CR>'
Dec 13 16:30:01 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+CPMS: 0,4,5,20,5,20<CR><LF><CR><LF>OK<CR><LF>'
Dec 13 16:30:01 t440s ModemManager[756]: <debug> Listing SMS parts in storage 'bm'
Dec 13 16:30:01 t440s ModemManager[756]: <debug> Locking SMS storages to: mem1 (BM), mem2 (none)...
Dec 13 16:30:01 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 3 (open)
Dec 13 16:30:01 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (close)
Dec 13 16:30:01 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+CPMS="BM"<CR>'
Dec 13 16:30:01 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+CPMS: 0,4,5,20,5,20<CR><LF><CR><LF>OK<CR><LF>'
Dec 13 16:30:01 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 3 (open)
Dec 13 16:30:01 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (close)
Dec 13 16:30:01 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+CMGL=4<CR>'
Dec 13 16:30:01 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Dec 13 16:30:01 t440s ModemManager[756]: <debug> Listing SMS parts in storage 'me'
Dec 13 16:30:01 t440s ModemManager[756]: <debug> Locking SMS storages to: mem1 (ME), mem2 (none)...
Dec 13 16:30:01 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 3 (open)
Dec 13 16:30:01 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (close)
Dec 13 16:30:01 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+CPMS="ME"<CR>'
Dec 13 16:30:02 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+CPMS: 0,4,5,20,5,20<CR><LF><CR><LF>OK<CR><LF>'
Dec 13 16:30:02 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 3 (open)
Dec 13 16:30:02 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (close)
Dec 13 16:30:02 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+CMGL=4<CR>'
Dec 13 16:30:02 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Dec 13 16:30:02 t440s ModemManager[756]: <debug> Listing SMS parts in storage 'sm'
Dec 13 16:30:02 t440s ModemManager[756]: <debug> Locking SMS storages to: mem1 (SM), mem2 (none)...
Dec 13 16:30:02 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 3 (open)
Dec 13 16:30:02 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (close)
Dec 13 16:30:02 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+CPMS="SM"<CR>'
Dec 13 16:30:02 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+CPMS: 5,20,5,20,5,20<CR><LF><CR><LF>OK<CR><LF>'
Dec 13 16:30:02 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 3 (open)
Dec 13 16:30:02 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (close)
Dec 13 16:30:02 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+CMGL=4<CR>'
Dec 13 16:30:02 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+CMGL: 1,1,,176<CR><LF>07919471227230336405812122F000F141706261221480A0050003DD0201AE69367BFD6EB7CB6E50DA0DE2CEE965B9BC9C1EA343A0669A0E4AA2E5E536C8FA2687CD6F7719747DCBD96410352C4F9B41FA309A5D7683A6E932C8EC9783826E79DD5C06B9C363348858AED3E763343BEC2683EA6E3228ED0671E7F4B25C5E4E8FD120775D0E92C958B61868487F35D36E16C8EC9783C2EEF5BBDD2EBBC96550D02DAF9BCBFFFFFFFFFFFFFFFFFFFFFF000000003C6F910B3C<CR><LF>'
Dec 13 16:30:02 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+CMGL: 2,1,,122<CR><LF>07919471227230336405812122F000F1417062612224806A050003DD0202403556AE061AD25FCDB4DB059A36A7A01B2B46030DE92C50B33905C9662C1C684877819C6FBABC6E06C562321668FD9ED3CB6EF67B5E0625DDE6376845CBC56EB2984C2683B940F7FBDD657F93C3E6B7BBEC22975FE53AFFFFFFFFFFFFFFFFFFFFFFFFFF<CR><LF>'
Dec 13 16:30:03 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+CMGL: 3,1,,176<CR><LF>07919471227230336405812235F300F141902100121180A0050003C9020198E9B2B82C0759DFE4B0F9ED2EB7967537B9CC02D5DB2062985E76CFCB727B7A5C9E83F47590BB4ED797DD2CD03CED26838A69F79C5E66B3EBEE73D90D4ABB4149B4BCDC0621C36E721EE4E6D3D36717C8E89783DA65B41C94749BDFF276989E7EBB41E732BAEC064DD3655039ED3687C768503B4D0725D1F2721B041D82DEE4B21CE47CD3CBFFFFFFFFFFFFFFFFFFFFFF000000003C6F910B3C<CR><LF>'
Dec 13 16:30:03 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+CMGL: 4,1,,86<CR><LF>07919471227230336405812235F300F14190210012218046050003C90202C4EFF71A14AE9B41F7FBDD657F93C3E6B7BBEC22975FEBB7DB9C3EBB40D674995D061DE57E4F99054AA2E520EB9B1C36BFDDE516B51C6E03FFFFFFFFFFFFFFFF<CR><LF>'
Dec 13 16:30:03 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+CMGL: 5,1,,56<CR><LF>0791947122720092040C919461927793650000419031220145802AD374190D22A6E52072780E0ABB4320349D0ED7BD5EE230F9FD768DDFEDD7FC756FBBD77138<CR><LF>'
Dec 13 16:30:03 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Dec 13 16:30:03 t440s ModemManager[756]: <debug> Parsing PDU (1)...
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   SMSC address parsed: '+491722270333'
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   Deliver type PDU detected
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   Number parsed: '12220'
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   PID: 0
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   user data encoding is GSM7
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   user data length: 160 elements
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   user data length: 140 bytes
Dec 13 16:30:03 t440s ModemManager[756]: <debug> Decoding SMS text with '153' elements
Dec 13 16:30:03 t440s ModemManager[756]: <debug> Converting SMS part text from GSM7 to UTF8...
Dec 13 16:30:03 t440s ModemManager[756]: <debug>    Got UTF-8 text: 'Willkommen in ?sterreich! Mit Ihrem Vodafone World Tarif zahlen Sie f?r Anrufe nach Deutschland und in ?sterreich nur 22,61 Ct/Min, f?r ankommende Anrufe'
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   user data encoding is GSM7
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   user data length: 160 elements
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   user data length: 140 bytes
Dec 13 16:30:03 t440s ModemManager[756]: <debug> Decoding SMS text with '153' elements
Dec 13 16:30:03 t440s ModemManager[756]: <debug> Converting SMS part text from GSM7 to UTF8...
Dec 13 16:30:03 t440s ModemManager[756]: <debug>    Got UTF-8 text: 'Lieber Vodafone-Kunde, um Datenservices zu nutzen, sind Einstellungen in Ihrem Handy n?tig. F?r mehr Information gehen Sie einfach mit Ihrem PC oder Note'
Dec 13 16:30:03 t440s ModemManager[756]: <debug> Correctly parsed PDU (3)
Dec 13 16:30:03 t440s ModemManager[756]: <debug> SMS part at 'sm/3' is from a multipart SMS (reference: '201', sequence: '1')
Dec 13 16:30:03 t440s ModemManager[756]: <debug> Added received SMS at '/org/freedesktop/ModemManager1/SMS/16'
Dec 13 16:30:03 t440s ModemManager[756]: <debug> Parsing PDU (4)...
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   SMSC address parsed: '+491722270333'
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   Deliver type PDU detected
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   Number parsed: '22533'
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   PID: 0
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   user data encoding is GSM7
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   user data length: 70 elements
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   user data length: 62 bytes
Dec 13 16:30:03 t440s ModemManager[756]: <debug> Decoding SMS text with '63' elements
Dec 13 16:30:03 t440s ModemManager[756]: <debug> Converting SMS part text from GSM7 to UTF8...
Dec 13 16:30:03 t440s ModemManager[756]: <debug>    Got UTF-8 text: 'book auf www.vodafone.de/konfig. Viele Gr??e, Ihr Vodafone-Team'
Dec 13 16:30:03 t440s ModemManager[756]: <debug> Correctly parsed PDU (4)
Dec 13 16:30:03 t440s ModemManager[756]: <debug> SMS part at 'sm/4' is from a multipart SMS (reference: '201', sequence: '2')
Dec 13 16:30:03 t440s ModemManager[756]: <debug> Parsing PDU (5)...
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   SMSC address parsed: '+491722270029'
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   Deliver type PDU detected
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   Number parsed: '+491629773956'
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   PID: 0
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   user data encoding is GSM7
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   user data length: 42 elements
Dec 13 16:30:03 t440s ModemManager[756]: <debug>   user data length: 37 bytes
Dec 13 16:30:03 t440s ModemManager[756]: <debug> Decoding SMS text with '42' elements
Dec 13 16:30:03 t440s ModemManager[756]: <debug> Converting SMS part text from GSM7 to UTF8...
Dec 13 16:30:03 t440s ModemManager[756]: <debug>    Got UTF-8 text: 'Sieh Dir das an! http://badoo.com/s/wmnkqp'
Dec 13 16:30:03 t440s ModemManager[756]: <debug> Correctly parsed PDU (5)
Dec 13 16:30:03 t440s ModemManager[756]: <debug> SMS part at 'sm/5' is from a singlepart SMS
Dec 13 16:30:03 t440s ModemManager[756]: <debug> Added received SMS at '/org/freedesktop/ModemManager1/SMS/17'
Dec 13 16:30:03 t440s ModemManager[756]: <debug> Listing SMS parts in storage 'sr'
Dec 13 16:30:03 t440s ModemManager[756]: <debug> Locking SMS storages to: mem1 (SR), mem2 (none)...
Dec 13 16:30:03 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 3 (open)
Dec 13 16:30:03 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (close)
Dec 13 16:30:03 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+CPMS="SR"<CR>'
Dec 13 16:30:03 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+CPMS: 0,4,5,20,5,20<CR><LF><CR><LF>OK<CR><LF>'
Dec 13 16:30:03 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 3 (open)
Dec 13 16:30:03 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (close)
Dec 13 16:30:03 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+CMGL=4<CR>'
Dec 13 16:30:04 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Dec 13 16:30:04 t440s ModemManager[756]: <debug> (ttyACM0) Setting messaging unsolicited events handlers
Dec 13 16:30:04 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 1 (close)
Dec 13 16:30:04 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (open)
Dec 13 16:30:04 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+CNMI=2,1,2,1,0<CR>'
Dec 13 16:30:04 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
Dec 13 16:30:04 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 1 (close)
Dec 13 16:30:04 t440s ModemManager[756]: <info>  Modem /org/freedesktop/ModemManager1/Modem/1: state changed (enabling -> registered)
Dec 13 16:30:04 t440s ModemManager[756]: <debug> Periodic signal quality checks enabled (interval = 3s)
Dec 13 16:30:04 t440s ModemManager[756]: <debug> loading signal quality...
Dec 13 16:30:04 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (open)
Dec 13 16:30:04 t440s ModemManager[756]: <debug> Periodic access technology checks enabled
Dec 13 16:30:04 t440s ModemManager[756]: <info>  Simple connect state (4/8): Wait to get fully enabled
Dec 13 16:30:04 t440s ModemManager[756]: <info>  Simple connect state (5/8): Register
Dec 13 16:30:04 t440s ModemManager[756]: <debug> Already registered in network '00320036003200300032', automatic registration not launched...
Dec 13 16:30:04 t440s ModemManager[756]: <info>  Simple connect state (6/8): Bearer
Dec 13 16:30:04 t440s ModemManager[756]: <debug> Creating new bearer...
Dec 13 16:30:04 t440s ModemManager[756]: <debug> Deleted disconnected bearer at '/org/freedesktop/ModemManager1/Bearer/4'
Dec 13 16:30:04 t440s ModemManager[756]: <debug> Removing from DBus bearer at '/org/freedesktop/ModemManager1/Bearer/4'
Dec 13 16:30:04 t440s ModemManager[756]: <debug> Creating Broadband bearer in broadband modem
Dec 13 16:30:04 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 3 (open)
Dec 13 16:30:04 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (close)
Dec 13 16:30:04 t440s ModemManager[756]: <debug> New bearer created at DBus path '/org/freedesktop/ModemManager1/Bearer/5'
Dec 13 16:30:04 t440s ModemManager[756]: <info>  Simple connect state (7/8): Connect
Dec 13 16:30:04 t440s ModemManager[756]: <debug> Connecting bearer '/org/freedesktop/ModemManager1/Bearer/5'
Dec 13 16:30:04 t440s ModemManager[756]: <info>  Modem /org/freedesktop/ModemManager1/Modem/1: state changed (registered -> connecting)
Dec 13 16:30:04 t440s ModemManager[756]: <debug> Launching 3GPP connection attempt with APN 'web.vodafone.de'
Dec 13 16:30:04 t440s ModemManager[756]: <debug> No specific IP family requested, defaulting to ipv4
Dec 13 16:30:04 t440s ModemManager[756]: <debug> Looking for best CID...
Dec 13 16:30:04 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 3 (open)
Dec 13 16:30:04 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+CSQ<CR>'
Dec 13 16:30:04 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+CSQ: 13,99<CR><LF><CR><LF>OK<CR><LF>'
Dec 13 16:30:04 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (close)
Dec 13 16:30:04 t440s ModemManager[756]: <debug> Modem /org/freedesktop/ModemManager1/Modem/1: signal quality updated (41)
Dec 13 16:30:04 t440s ModemManager[756]: <debug> Periodic signal quality checks rescheduled (interval = 30s)
Dec 13 16:30:04 t440s ModemManager[756]: <debug> (ttyACM0): --> 'AT+CGDCONT?<CR>'
Dec 13 16:30:04 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>+CGDCONT: 1,"IPV4V6","","",0,0<CR><LF><CR><LF>+CGDCONT: 2,"IP","web.vodafone.de","0.0.0.0",0,0,0,0,0,0<CR><LF><CR><LF>OK<CR><LF>'
Dec 13 16:30:04 t440s ModemManager[756]: <debug> Found '2' PDP contexts
Dec 13 16:30:04 t440s ModemManager[756]: <debug>   PDP context [cid=1] [type='ipv4v6'] [apn='']
Dec 13 16:30:04 t440s ModemManager[756]: <debug>   PDP context [cid=2] [type='ipv4'] [apn='web.vodafone.de']
Dec 13 16:30:04 t440s ModemManager[756]: <debug> Found PDP context with CID 2 and PDP type ipv4 for APN 'web.vodafone.de'
Dec 13 16:30:04 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 3 (open)
Dec 13 16:30:04 t440s ModemManager[756]: <debug> Connection through a plain serial AT port (ttyACM0)
Dec 13 16:30:04 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 4 (open)
Dec 13 16:30:04 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 3 (close)
Dec 13 16:30:04 t440s ModemManager[756]: <debug> (ttyACM0): --> 'ATD*99***2#<CR>'
Dec 13 16:30:04 t440s ModemManager[756]: <debug> (ttyACM0): <-- '<CR><LF>CONNECT<CR><LF>'
Dec 13 16:30:04 t440s ModemManager[756]: <debug> (ttyACM0) device open count is 2 (close)
Dec 13 16:30:04 t440s ModemManager[756]: <debug> (ttyACM0): port now connected
Dec 13 16:30:04 t440s ModemManager[756]: <debug> Connected bearer '/org/freedesktop/ModemManager1/Bearer/5'
Dec 13 16:30:04 t440s ModemManager[756]: <info>  Modem /org/freedesktop/ModemManager1/Modem/1: state changed (connecting -> connected)
Dec 13 16:30:04 t440s ModemManager[756]: <info>  Simple connect state (8/8): All done



More information about the Pkg-utopia-maintainers mailing list