[Pkg-utopia-maintainers] Bug#752763: Regression: ZTE K3806-Z stopped working ("Invalid mobile equipment error code: 765")

Pietro Battiston me at pietrobattiston.it
Thu Jun 26 11:32:25 UTC 2014


Package: modemmanager
Version: 1.0.0-5
Severity: important

Although I can't say exactly which was the last version working (I only know
that 1.0.0-4 and 1.0.0-5 don't), I used to use without any problems my ZTE
K3806-Z USB key in the past.

Now instead since probably a couple of months if I try to connect, the network-
manager applet shows that the connection was established, but in fact no remote
address can be reached.

It is a specific problem of this USB key, since I still have no problem
connecting with a Huawei K-3765 (same SIM, same network-manager connection).

Moreover, the problematic key still works smoothly on another (openwrt) system.

I am attaching the relevant syslog part for each of the two USB keys (from
plugging in the device until connection appears to be established), plus the
output of "sudo route -n" after each.
In the logs for the ZTE key, the one not working, there are several "Invalid
mobile equipment error code: 765" messages which seem suspect, but googling for
them I only found two bugs which didn't enlighten me particularly.

-- System Information:
Debian Release: jessie/sid
  APT prefers testing
  APT policy: (650, 'testing'), (500, 'oldstable-updates')
Architecture: amd64 (x86_64)
Foreign Architectures: i386

Kernel: Linux 3.14-1-amd64 (SMP w/2 CPU cores)
Locale: LANG=it_IT.utf8, LC_CTYPE=it_IT.utf8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash

Versions of packages modemmanager depends on:
ii  init-system-helpers    1.18
ii  libc6                  2.18-5
ii  libglib2.0-0           2.40.0-3
ii  libgudev-1.0-0         204-8
ii  libmbim-glib0          1.8.0-1
ii  libmm-glib0            1.0.0-4
ii  libpolkit-gobject-1-0  0.105-5
ii  libqmi-glib0           1.4.0-1

Versions of packages modemmanager recommends:
ii  usb-modeswitch  2.1.1+repack0-1

modemmanager suggests no packages.
-------------- next part --------------
Jun 26 13:06:54 debiousci kernel: [ 6401.936215] usb 2-6: new high-speed USB device number 24 using ehci-pci
Jun 26 13:06:54 debiousci kernel: [ 6402.071627] usb 2-6: New USB device found, idVendor=19d2, idProduct=1013
Jun 26 13:06:54 debiousci kernel: [ 6402.071640] usb 2-6: New USB device strings: Mfr=2, Product=1, SerialNumber=3
Jun 26 13:06:54 debiousci kernel: [ 6402.071647] usb 2-6: Product: K3806-Z
Jun 26 13:06:54 debiousci kernel: [ 6402.071654] usb 2-6: Manufacturer: Vodafone (ZTE)
Jun 26 13:06:54 debiousci kernel: [ 6402.071660] usb 2-6: SerialNumber: A9883D564654C8C1FE5FF25A0A76E5CB1E376BC1
Jun 26 13:06:54 debiousci kernel: [ 6402.073220] usb-storage 2-6:1.0: USB Mass Storage device detected
Jun 26 13:06:54 debiousci kernel: [ 6402.073776] scsi30 : usb-storage 2-6:1.0
Jun 26 13:06:54 debiousci mtp-probe: checking bus 2, device 24: "/sys/devices/pci0000:00/0000:00:1d.7/usb2/2-6"
Jun 26 13:06:54 debiousci mtp-probe: bus: 2, device: 24 was not an MTP device
Jun 26 13:06:54 debiousci console-kit-daemon[2911]: GLib-CRITICAL: Source ID 1537 was not found when attempting to remove it
Jun 26 13:06:54 debiousci usb_modeswitch: switch device 19d2:1013 on 002/024
Jun 26 13:06:54 debiousci kernel: [ 6402.626127] usb 2-6: USB disconnect, device number 24
Jun 26 13:06:56 debiousci console-kit-daemon[2911]: GLib-CRITICAL: Source ID 1546 was not found when attempting to remove it
Jun 26 13:07:02 debiousci kernel: [ 6410.192160] usb 2-6: new high-speed USB device number 25 using ehci-pci
Jun 26 13:07:02 debiousci kernel: [ 6410.326754] usb 2-6: New USB device found, idVendor=19d2, idProduct=1015
Jun 26 13:07:02 debiousci kernel: [ 6410.326767] usb 2-6: New USB device strings: Mfr=3, Product=2, SerialNumber=4
Jun 26 13:07:02 debiousci kernel: [ 6410.326775] usb 2-6: Product: K3806-Z
Jun 26 13:07:02 debiousci kernel: [ 6410.326782] usb 2-6: Manufacturer: Vodafone (ZTE)
Jun 26 13:07:02 debiousci kernel: [ 6410.326788] usb 2-6: SerialNumber: A9883D564654C8C1FE5FF25A0A76E5CB1E376BC1
Jun 26 13:07:02 debiousci kernel: [ 6410.328374] cdc_acm 2-6:1.1: ttyACM1: USB ACM device
Jun 26 13:07:02 debiousci kernel: [ 6410.329908] cdc_acm 2-6:1.3: ttyACM2: USB ACM device
Jun 26 13:07:02 debiousci kernel: [ 6410.332453] cdc_ether 2-6:1.5 wwan0: register 'cdc_ether' at usb-0000:00:1d.7-6, Mobile Broadband Network Device, 02:54:c8:c1:fe:5f
Jun 26 13:07:02 debiousci kernel: [ 6410.333053] usb-storage 2-6:1.7: USB Mass Storage device detected
Jun 26 13:07:02 debiousci kernel: [ 6410.333369] scsi31 : usb-storage 2-6:1.7
Jun 26 13:07:02 debiousci mtp-probe: checking bus 2, device 25: "/sys/devices/pci0000:00/0000:00:1d.7/usb2/2-6"
Jun 26 13:07:02 debiousci mtp-probe: bus: 2, device: 25 was not an MTP device
Jun 26 13:07:02 debiousci NetworkManager[2344]:    SCPlugin-Ifupdown: devices added (path: /sys/devices/pci0000:00/0000:00:1d.7/usb2/2-6/2-6:1.5/net/wwan0, iface: wwan0)
Jun 26 13:07:02 debiousci NetworkManager[2344]:    SCPlugin-Ifupdown: device added (path: /sys/devices/pci0000:00/0000:00:1d.7/usb2/2-6/2-6:1.5/net/wwan0, iface: wwan0): no ifupdown configuration found.
Jun 26 13:07:02 debiousci logger: usb_modeswitch: switched to 19d2:1015 on 002/025
Jun 26 13:07:03 debiousci kernel: [ 6411.333940] scsi 31:0:0:0: CD-ROM            Vodafone USB SCSI CD-ROM  0001 PQ: 0 ANSI: 0
Jun 26 13:07:03 debiousci kernel: [ 6411.335310] scsi 31:0:0:1: Direct-Access     Vodafone Storage          0001 PQ: 0 ANSI: 0
Jun 26 13:07:03 debiousci kernel: [ 6411.338303] sr1: scsi3-mmc drive: 0x/0x caddy
Jun 26 13:07:03 debiousci kernel: [ 6411.338576] sr 31:0:0:0: Attached scsi CD-ROM sr1
Jun 26 13:07:03 debiousci kernel: [ 6411.338749] sr 31:0:0:0: Attached scsi generic sg3 type 5
Jun 26 13:07:03 debiousci kernel: [ 6411.339130] sd 31:0:0:1: Attached scsi generic sg4 type 0
Jun 26 13:07:03 debiousci kernel: [ 6411.340431] sd 31:0:0:1: [sdc] 15564800 512-byte logical blocks: (7.96 GB/7.42 GiB)
Jun 26 13:07:03 debiousci kernel: [ 6411.343041] sd 31:0:0:1: [sdc] Write Protect is off
Jun 26 13:07:03 debiousci kernel: [ 6411.343046] sd 31:0:0:1: [sdc] Mode Sense: 0f 00 00 00
Jun 26 13:07:03 debiousci kernel: [ 6411.344813] sd 31:0:0:1: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Jun 26 13:07:03 debiousci kernel: [ 6411.357705]  sdc: sdc1
Jun 26 13:07:03 debiousci kernel: [ 6411.360395] sd 31:0:0:1: [sdc] Attached SCSI removable disk
Jun 26 13:07:03 debiousci kernel: [ 6411.421474] sr1: CDROM (ioctl) error, command: Xpwrite, Read disk info 51 00 00 00 00 00 00 00 02 00
Jun 26 13:07:03 debiousci kernel: [ 6411.421486] sr: Sense Key : Hardware Error [current] 
Jun 26 13:07:03 debiousci kernel: [ 6411.421490] sr: Add. Sense: No additional sense information
Jun 26 13:07:05 debiousci ModemManager[4229]: <info>  Creating modem with plugin 'ZTE' and '3' ports
Jun 26 13:07:05 debiousci ModemManager[4229]: <info>  Modem for device at '/sys/devices/pci0000:00/0000:00:1d.7/usb2/2-6' successfully created
Jun 26 13:07:05 debiousci ModemManager[4229]: Invalid mobile equipment error code: 765
Jun 26 13:07:05 debiousci ModemManager[4229]: Invalid mobile equipment error code: 765
Jun 26 13:07:05 debiousci ModemManager[4229]: Invalid mobile equipment error code: 765
Jun 26 13:07:05 debiousci ModemManager[4229]: Invalid mobile equipment error code: 765
Jun 26 13:07:05 debiousci ModemManager[4229]: Invalid mobile equipment error code: 765
Jun 26 13:07:06 debiousci ModemManager[4229]: <info>  Modem: state changed (unknown -> disabled)
Jun 26 13:07:06 debiousci NetworkManager[2344]: <warn> (ttyACM1): failed to look up interface index
Jun 26 13:07:06 debiousci NetworkManager[2344]: <info> (ttyACM1): new Broadband device (driver: 'cdc_acm, cdc_ether' ifindex: 0)
Jun 26 13:07:06 debiousci NetworkManager[2344]: <info> (ttyACM1): exported as /org/freedesktop/NetworkManager/Devices/10
Jun 26 13:07:06 debiousci NetworkManager[2344]: <info> (ttyACM1): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Jun 26 13:07:06 debiousci NetworkManager[2344]: <info> (ttyACM1): deactivating device (reason 'managed') [2]
Jun 26 13:07:06 debiousci NetworkManager[2344]: <info> (ttyACM1): device state change: unavailable -> disconnected (reason 'none') [20 30 0]
Jun 26 13:07:10 debiousci NetworkManager[2344]: <info> Activation (ttyACM1) starting connection 'Wind'
Jun 26 13:07:10 debiousci NetworkManager[2344]: <info> (ttyACM1): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Jun 26 13:07:10 debiousci NetworkManager[2344]: <info> NetworkManager state is now CONNECTING
Jun 26 13:07:10 debiousci NetworkManager[2344]: <info> Activation (ttyACM1) Stage 1 of 5 (Device Prepare) scheduled...
Jun 26 13:07:10 debiousci NetworkManager[2344]: <info> Activation (ttyACM1) Stage 1 of 5 (Device Prepare) started...
Jun 26 13:07:10 debiousci NetworkManager[2344]: <info> Activation (ttyACM1) Stage 1 of 5 (Device Prepare) complete.
Jun 26 13:07:10 debiousci ModemManager[4229]: <info>  Simple connect started...
Jun 26 13:07:10 debiousci ModemManager[4229]: <info>  Simple connect state (3/8): Enable
Jun 26 13:07:10 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/8: state changed (disabled -> enabling)
Jun 26 13:07:10 debiousci NetworkManager[2344]: <info> (ttyACM1) modem state changed, 'disabled' --> 'enabling' (reason: user-requested)
Jun 26 13:07:10 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/8: signal quality updated (0)
Jun 26 13:07:10 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/8: 3GPP Registration state changed (unknown -> searching)
Jun 26 13:07:10 debiousci ModemManager[4229]: Invalid message error code: 518
Jun 26 13:07:11 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/8: state changed (enabling -> searching)
Jun 26 13:07:11 debiousci NetworkManager[2344]: <info> (ttyACM1) modem state changed, 'enabling' --> 'searching' (reason: user-requested)
Jun 26 13:07:11 debiousci ModemManager[4229]: <info>  Simple connect state (4/8): Wait to get fully enabled
Jun 26 13:07:11 debiousci ModemManager[4229]: <info>  Simple connect state (5/8): Register
Jun 26 13:07:14 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/8: signal quality updated (0)
Jun 26 13:07:17 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/8: 3GPP Registration state changed (searching -> registering)
Jun 26 13:07:17 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/8: signal quality updated (80)
Jun 26 13:07:17 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/8: access technology changed (unknown -> umts)
Jun 26 13:07:17 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/8: 3GPP location updated (MCC: '222', MNC: '88', Location area code: '0', Cell ID: '0')
Jun 26 13:07:17 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/8: 3GPP location updated (MCC: '0', MNC: '0', Location area code: '0', Cell ID: '0')
Jun 26 13:07:17 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/8: signal quality updated (80)
Jun 26 13:07:17 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/8: 3GPP Registration state changed (registering -> home)
Jun 26 13:07:17 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/8: state changed (searching -> registered)
Jun 26 13:07:17 debiousci NetworkManager[2344]: <info> (ttyACM1) modem state changed, 'searching' --> 'registered' (reason: unknown)
Jun 26 13:07:17 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/8: signal quality updated (80)
Jun 26 13:07:17 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/8: signal quality updated (29)
Jun 26 13:07:20 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/8: signal quality updated (60)
Jun 26 13:07:20 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/8: 3GPP location updated (MCC: '0', MNC: '0', Location area code: '5E00', Cell ID: '129955A')
Jun 26 13:07:20 debiousci ModemManager[4229]: <info>  Simple connect state (6/8): Bearer
Jun 26 13:07:20 debiousci ModemManager[4229]: <info>  Simple connect state (7/8): Connect
Jun 26 13:07:20 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/8: state changed (registered -> connecting)
Jun 26 13:07:20 debiousci NetworkManager[2344]: <info> (ttyACM1) modem state changed, 'registered' --> 'connecting' (reason: user-requested)
Jun 26 13:07:20 debiousci ModemManager[4229]: Invalid mobile equipment error code: 767
Jun 26 13:07:22 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/8: signal quality updated (60)
Jun 26 13:07:23 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/8: signal quality updated (60)
Jun 26 13:07:23 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/8: access technology changed (umts -> hspa)
Jun 26 13:07:23 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/8: state changed (connecting -> connected)
Jun 26 13:07:23 debiousci NetworkManager[2344]: <info> (ttyACM1) modem state changed, 'connecting' --> 'connected' (reason: user-requested)
Jun 26 13:07:23 debiousci ModemManager[4229]: <info>  Simple connect state (8/8): All done
Jun 26 13:07:23 debiousci NetworkManager[2344]: <info> Activation (ttyACM1) Stage 2 of 5 (Device Configure) scheduled...
Jun 26 13:07:23 debiousci NetworkManager[2344]: <info> Activation (ttyACM1) Stage 2 of 5 (Device Configure) starting...
Jun 26 13:07:23 debiousci NetworkManager[2344]: <info> (ttyACM1): device state change: prepare -> config (reason 'none') [40 50 0]
Jun 26 13:07:23 debiousci NetworkManager[2344]: <info> (ttyACM1): bringing up device.
Jun 26 13:07:24 debiousci NetworkManager[2344]: <info> Activation (ttyACM1) Stage 2 of 5 (Device Configure) successful.
Jun 26 13:07:24 debiousci NetworkManager[2344]: <info> Activation (ttyACM1) Stage 3 of 5 (IP Configure Start) scheduled.
Jun 26 13:07:24 debiousci NetworkManager[2344]: <info> Activation (ttyACM1) Stage 2 of 5 (Device Configure) complete.
Jun 26 13:07:24 debiousci NetworkManager[2344]: <info> Activation (ttyACM1) Stage 3 of 5 (IP Configure Start) started...
Jun 26 13:07:24 debiousci NetworkManager[2344]: <info> (ttyACM1): device state change: config -> ip-config (reason 'none') [50 70 0]
Jun 26 13:07:24 debiousci NetworkManager[2344]: <info> Activation (ttyACM1) Stage 4 of 5 (IPv6 Configure Timeout) scheduled...
Jun 26 13:07:24 debiousci NetworkManager[2344]: <info> Activation (ttyACM1) Stage 3 of 5 (IP Configure Start) complete.
Jun 26 13:07:24 debiousci NetworkManager[2344]: <info> (ttyACM1): IPv4 static configuration:
Jun 26 13:07:24 debiousci NetworkManager[2344]: <info>   address 10.234.52.35/8
Jun 26 13:07:24 debiousci NetworkManager[2344]: <info>   DNS 212.52.97.25
Jun 26 13:07:24 debiousci NetworkManager[2344]: <info>   DNS 193.70.152.25
Jun 26 13:07:24 debiousci NetworkManager[2344]: <info> Activation (ttyACM1) Stage 5 of 5 (IPv4 Configure Commit) scheduled...
Jun 26 13:07:24 debiousci NetworkManager[2344]: <info> Activation (ttyACM1) Stage 4 of 5 (IPv6 Configure Timeout) started...
Jun 26 13:07:24 debiousci NetworkManager[2344]: <info> Activation (ttyACM1) Stage 4 of 5 (IPv6 Configure Timeout) complete.
Jun 26 13:07:24 debiousci NetworkManager[2344]: <info> Activation (ttyACM1) Stage 5 of 5 (IPv4 Commit) started...
Jun 26 13:07:24 debiousci avahi-daemon[12170]: Joining mDNS multicast group on interface wwan0.IPv4 with address 10.234.52.35.
Jun 26 13:07:24 debiousci avahi-daemon[12170]: New relevant interface wwan0.IPv4 for mDNS.
Jun 26 13:07:24 debiousci avahi-daemon[12170]: Registering new address record for 10.234.52.35 on wwan0.IPv4.
Jun 26 13:07:25 debiousci NetworkManager[2344]: <info> (ttyACM1): device state change: ip-config -> secondaries (reason 'none') [70 90 0]
Jun 26 13:07:25 debiousci NetworkManager[2344]: <info> Activation (ttyACM1) Stage 5 of 5 (IPv4 Commit) complete.
Jun 26 13:07:25 debiousci NetworkManager[2344]: <info> (ttyACM1): device state change: secondaries -> activated (reason 'none') [90 100 0]
Jun 26 13:07:25 debiousci NetworkManager[2344]: <info> NetworkManager state is now CONNECTED_GLOBAL
Jun 26 13:07:25 debiousci NetworkManager[2344]: <info> Policy set 'Wind' (wwan0) as default for IPv4 routing and DNS.
Jun 26 13:07:25 debiousci NetworkManager[2344]: <info> Activation (ttyACM1) successful, device activated.
Jun 26 13:07:25 debiousci dbus[2302]: [system] Activating service name='org.freedesktop.nm_dispatcher' (using servicehelper)
Jun 26 13:07:25 debiousci dbus[2302]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Jun 26 13:07:25 debiousci avahi-daemon[12170]: Joining mDNS multicast group on interface wwan0.IPv6 with address fe80::54:c8ff:fec1:fe5f.
Jun 26 13:07:25 debiousci avahi-daemon[12170]: New relevant interface wwan0.IPv6 for mDNS.
Jun 26 13:07:25 debiousci avahi-daemon[12170]: Registering new address record for fe80::54:c8ff:fec1:fe5f on wwan0.*.
Jun 26 13:07:28 debiousci nm-dispatcher.action: Script '/etc/NetworkManager/dispatcher.d/01ifupdown' took too long; killing it.
Jun 26 13:07:28 debiousci NetworkManager[2344]: <warn> Dispatcher script timed out: Script '/etc/NetworkManager/dispatcher.d/01ifupdown' timed out.
Jun 26 13:07:31 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/8: signal quality updated (80)
-------------- next part --------------
Jun 26 13:04:10 debiousci kernel: [ 6238.548097] usb 2-5: new high-speed USB device number 22 using ehci-pci
Jun 26 13:04:10 debiousci kernel: [ 6238.684297] usb 2-5: New USB device found, idVendor=12d1, idProduct=1520
Jun 26 13:04:10 debiousci kernel: [ 6238.684309] usb 2-5: New USB device strings: Mfr=3, Product=2, SerialNumber=0
Jun 26 13:04:10 debiousci kernel: [ 6238.684316] usb 2-5: Product: HUAWEI Mobile
Jun 26 13:04:10 debiousci kernel: [ 6238.684323] usb 2-5: Manufacturer: HUAWEI Technology
Jun 26 13:04:10 debiousci kernel: [ 6238.685761] usb-storage 2-5:1.0: USB Mass Storage device detected
Jun 26 13:04:10 debiousci kernel: [ 6238.686062] scsi27 : usb-storage 2-5:1.0
Jun 26 13:04:10 debiousci mtp-probe: checking bus 2, device 22: "/sys/devices/pci0000:00/0000:00:1d.7/usb2/2-5"
Jun 26 13:04:10 debiousci mtp-probe: bus: 2, device: 22 was not an MTP device
Jun 26 13:04:11 debiousci usb_modeswitch: switch device 12d1:1520 on 002/022
Jun 26 13:04:11 debiousci kernel: [ 6239.237408] usb 2-5: USB disconnect, device number 22
Jun 26 13:04:15 debiousci kernel: [ 6243.420152] usb 2-5: new high-speed USB device number 23 using ehci-pci
Jun 26 13:04:15 debiousci kernel: [ 6243.556306] usb 2-5: New USB device found, idVendor=12d1, idProduct=1465
Jun 26 13:04:15 debiousci kernel: [ 6243.556320] usb 2-5: New USB device strings: Mfr=4, Product=3, SerialNumber=0
Jun 26 13:04:15 debiousci kernel: [ 6243.556328] usb 2-5: Product: HUAWEI Mobile
Jun 26 13:04:15 debiousci kernel: [ 6243.556334] usb 2-5: Manufacturer: HUAWEI Technology
Jun 26 13:04:15 debiousci kernel: [ 6243.559295] option 2-5:1.0: GSM modem (1-port) converter detected
Jun 26 13:04:15 debiousci kernel: [ 6243.559618] usb 2-5: GSM modem (1-port) converter now attached to ttyUSB0
Jun 26 13:04:15 debiousci kernel: [ 6243.561621] cdc_ether 2-5:1.1 wwan0: register 'cdc_ether' at usb-0000:00:1d.7-5, Mobile Broadband Network Device, 02:50:f3:00:00:00
Jun 26 13:04:15 debiousci kernel: [ 6243.561994] option 2-5:1.3: GSM modem (1-port) converter detected
Jun 26 13:04:15 debiousci kernel: [ 6243.562242] usb 2-5: GSM modem (1-port) converter now attached to ttyUSB1
Jun 26 13:04:15 debiousci kernel: [ 6243.562467] option 2-5:1.4: GSM modem (1-port) converter detected
Jun 26 13:04:15 debiousci kernel: [ 6243.562648] usb 2-5: GSM modem (1-port) converter now attached to ttyUSB2
Jun 26 13:04:15 debiousci kernel: [ 6243.562868] usb-storage 2-5:1.5: USB Mass Storage device detected
Jun 26 13:04:15 debiousci kernel: [ 6243.563117] scsi28 : usb-storage 2-5:1.5
Jun 26 13:04:15 debiousci kernel: [ 6243.563510] usb-storage 2-5:1.6: USB Mass Storage device detected
Jun 26 13:04:15 debiousci kernel: [ 6243.563718] scsi29 : usb-storage 2-5:1.6
Jun 26 13:04:15 debiousci mtp-probe: checking bus 2, device 23: "/sys/devices/pci0000:00/0000:00:1d.7/usb2/2-5"
Jun 26 13:04:15 debiousci mtp-probe: bus: 2, device: 23 was not an MTP device
Jun 26 13:04:15 debiousci NetworkManager[2344]:    SCPlugin-Ifupdown: devices added (path: /sys/devices/pci0000:00/0000:00:1d.7/usb2/2-5/2-5:1.1/net/wwan0, iface: wwan0)
Jun 26 13:04:15 debiousci NetworkManager[2344]:    SCPlugin-Ifupdown: device added (path: /sys/devices/pci0000:00/0000:00:1d.7/usb2/2-5/2-5:1.1/net/wwan0, iface: wwan0): no ifupdown configuration found.
Jun 26 13:04:15 debiousci ModemManager[4229]: <warn>  (ttyUSB2): port attributes not fully set
Jun 26 13:04:15 debiousci ModemManager[4229]: <warn>  (ttyUSB1): port attributes not fully set
Jun 26 13:04:15 debiousci ModemManager[4229]: <warn>  (ttyUSB0): port attributes not fully set
Jun 26 13:04:16 debiousci logger: usb_modeswitch: switched to 12d1:1465 on 002/023
Jun 26 13:04:16 debiousci kernel: [ 6244.570189] scsi 28:0:0:0: CD-ROM            Vodafone CD ROM (Huawei)  2.31 PQ: 0 ANSI: 2
Jun 26 13:04:16 debiousci kernel: [ 6244.571951] scsi 29:0:0:0: Direct-Access     Vodafone Storage (Huawei) 2.31 PQ: 0 ANSI: 2
Jun 26 13:04:16 debiousci kernel: [ 6244.579666] sr1: scsi-1 drive
Jun 26 13:04:16 debiousci kernel: [ 6244.580337] sr 28:0:0:0: Attached scsi CD-ROM sr1
Jun 26 13:04:16 debiousci kernel: [ 6244.582247] sr 28:0:0:0: Attached scsi generic sg3 type 5
Jun 26 13:04:16 debiousci kernel: [ 6244.589203] sd 29:0:0:0: Attached scsi generic sg4 type 0
Jun 26 13:04:16 debiousci kernel: [ 6244.591868] sd 29:0:0:0: [sdc] Attached SCSI removable disk
Jun 26 13:04:19 debiousci ModemManager[4229]: <warn>  (ttyUSB2): port attributes not fully set
Jun 26 13:04:19 debiousci ModemManager[4229]: <warn>  (ttyUSB1): port attributes not fully set
Jun 26 13:04:29 debiousci ModemManager[4229]: <info>  Creating modem with plugin 'Huawei' and '4' ports
Jun 26 13:04:29 debiousci ModemManager[4229]: <warn>  (ttyUSB2): port attributes not fully set
Jun 26 13:04:29 debiousci ModemManager[4229]: <info>  Modem for device at '/sys/devices/pci0000:00/0000:00:1d.7/usb2/2-5' successfully created
Jun 26 13:04:30 debiousci console-kit-daemon[2911]: GLib-CRITICAL: Source ID 1474 was not found when attempting to remove it
Jun 26 13:04:33 debiousci ModemManager[4229]: <info>  Modem: state changed (unknown -> disabled)
Jun 26 13:04:33 debiousci NetworkManager[2344]: <warn> (ttyUSB2): failed to look up interface index
Jun 26 13:04:33 debiousci NetworkManager[2344]: <info> (ttyUSB2): new Broadband device (driver: 'cdc_ether, option1' ifindex: 0)
Jun 26 13:04:33 debiousci NetworkManager[2344]: <info> (ttyUSB2): exported as /org/freedesktop/NetworkManager/Devices/9
Jun 26 13:04:33 debiousci NetworkManager[2344]: <info> (ttyUSB2): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Jun 26 13:04:33 debiousci NetworkManager[2344]: <info> (ttyUSB2): deactivating device (reason 'managed') [2]
Jun 26 13:04:33 debiousci NetworkManager[2344]: <info> (ttyUSB2): device state change: unavailable -> disconnected (reason 'none') [20 30 0]
Jun 26 13:05:08 debiousci console-kit-daemon[2911]: GLib-CRITICAL: Source ID 1483 was not found when attempting to remove it
Jun 26 13:05:11 debiousci NetworkManager[2344]: <info> Activation (ttyUSB2) starting connection 'Wind'
Jun 26 13:05:11 debiousci NetworkManager[2344]: <info> (ttyUSB2): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Jun 26 13:05:11 debiousci NetworkManager[2344]: <info> NetworkManager state is now CONNECTING
Jun 26 13:05:11 debiousci NetworkManager[2344]: <info> Activation (ttyUSB2) Stage 1 of 5 (Device Prepare) scheduled...
Jun 26 13:05:11 debiousci NetworkManager[2344]: <info> Activation (ttyUSB2) Stage 1 of 5 (Device Prepare) started...
Jun 26 13:05:11 debiousci NetworkManager[2344]: <info> Activation (ttyUSB2) Stage 1 of 5 (Device Prepare) complete.
Jun 26 13:05:11 debiousci ModemManager[4229]: <info>  Simple connect started...
Jun 26 13:05:11 debiousci ModemManager[4229]: <info>  Simple connect state (3/8): Enable
Jun 26 13:05:11 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/7: state changed (disabled -> enabling)
Jun 26 13:05:11 debiousci NetworkManager[2344]: <info> (ttyUSB2) modem state changed, 'disabled' --> 'enabling' (reason: user-requested)
Jun 26 13:05:11 debiousci ModemManager[4229]: <warn>  (ttyUSB2): port attributes not fully set
Jun 26 13:05:11 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/7: 3GPP Registration state changed (unknown -> registering)
Jun 26 13:05:11 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/7: 3GPP Registration state changed (registering -> home)
Jun 26 13:05:11 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/7: 3GPP location updated (MCC: '222', MNC: '88', Location area code: '0', Cell ID: '0')
Jun 26 13:05:11 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/7: state changed (enabling -> registered)
Jun 26 13:05:11 debiousci ModemManager[4229]: <info>  Simple connect state (4/8): Wait to get fully enabled
Jun 26 13:05:11 debiousci ModemManager[4229]: <info>  Simple connect state (5/8): Register
Jun 26 13:05:11 debiousci ModemManager[4229]: <info>  Simple connect state (6/8): Bearer
Jun 26 13:05:11 debiousci NetworkManager[2344]: <info> (ttyUSB2) modem state changed, 'enabling' --> 'registered' (reason: user-requested)
Jun 26 13:05:11 debiousci ModemManager[4229]: <info>  Simple connect state (7/8): Connect
Jun 26 13:05:11 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/7: state changed (registered -> connecting)
Jun 26 13:05:11 debiousci NetworkManager[2344]: <info> (ttyUSB2) modem state changed, 'registered' --> 'connecting' (reason: user-requested)
Jun 26 13:05:11 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/7: signal quality updated (40)
Jun 26 13:05:11 debiousci ModemManager[4229]: <warn>  (ttyUSB0): port attributes not fully set
Jun 26 13:05:12 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/7: access technology changed (unknown -> umts)
Jun 26 13:05:12 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/7: state changed (connecting -> connected)
Jun 26 13:05:12 debiousci NetworkManager[2344]: <info> (ttyUSB2) modem state changed, 'connecting' --> 'connected' (reason: user-requested)
Jun 26 13:05:12 debiousci ModemManager[4229]: <info>  Simple connect state (8/8): All done
Jun 26 13:05:12 debiousci NetworkManager[2344]: <warn> (ttyUSB0): failed to look up interface index
Jun 26 13:05:12 debiousci NetworkManager[2344]: <info> Activation (ttyUSB2) Stage 2 of 5 (Device Configure) scheduled...
Jun 26 13:05:12 debiousci NetworkManager[2344]: <info> Activation (ttyUSB2) Stage 2 of 5 (Device Configure) starting...
Jun 26 13:05:12 debiousci NetworkManager[2344]: <info> (ttyUSB2): device state change: prepare -> config (reason 'none') [40 50 0]
Jun 26 13:05:12 debiousci NetworkManager[2344]: <info> Activation (ttyUSB2) Stage 2 of 5 (Device Configure) successful.
Jun 26 13:05:12 debiousci NetworkManager[2344]: <info> Activation (ttyUSB2) Stage 3 of 5 (IP Configure Start) scheduled.
Jun 26 13:05:12 debiousci NetworkManager[2344]: <info> Activation (ttyUSB2) Stage 2 of 5 (Device Configure) complete.
Jun 26 13:05:12 debiousci NetworkManager[2344]: <info> Activation (ttyUSB2) Stage 3 of 5 (IP Configure Start) started...
Jun 26 13:05:12 debiousci NetworkManager[2344]: <info> (ttyUSB2): device state change: config -> ip-config (reason 'none') [50 70 0]
Jun 26 13:05:12 debiousci NetworkManager[2344]: <info> using modem-specified IP timeout: 20 seconds
Jun 26 13:05:12 debiousci NetworkManager[2344]: <info> starting PPP connection
Jun 26 13:05:12 debiousci NetworkManager[2344]: <info> pppd started with pid 17824
Jun 26 13:05:12 debiousci NetworkManager[2344]: <info> Activation (ttyUSB2) Stage 4 of 5 (IPv6 Configure Timeout) scheduled...
Jun 26 13:05:12 debiousci NetworkManager[2344]: <info> Activation (ttyUSB2) Stage 3 of 5 (IP Configure Start) complete.
Jun 26 13:05:12 debiousci pppd[17824]: Plugin /usr/lib/pppd/2.4.6/nm-pppd-plugin.so loaded.
Jun 26 13:05:12 debiousci pppd[17824]: pppd 2.4.6 started by root, uid 0
Jun 26 13:05:12 debiousci pppd[17824]: Using interface ppp0
Jun 26 13:05:12 debiousci pppd[17824]: Connect: ppp0 <--> /dev/ttyUSB0
Jun 26 13:05:12 debiousci NetworkManager[2344]:    SCPlugin-Ifupdown: devices added (path: /sys/devices/virtual/net/ppp0, iface: ppp0)
Jun 26 13:05:12 debiousci NetworkManager[2344]:    SCPlugin-Ifupdown: device added (path: /sys/devices/virtual/net/ppp0, iface: ppp0): no ifupdown configuration found.
Jun 26 13:05:12 debiousci NetworkManager[2344]: <warn> /sys/devices/virtual/net/ppp0: couldn't determine device driver; ignoring...
Jun 26 13:05:12 debiousci NetworkManager[2344]: <info> Activation (ttyUSB2) Stage 4 of 5 (IPv6 Configure Timeout) started...
Jun 26 13:05:12 debiousci NetworkManager[2344]: <info> Activation (ttyUSB2) Stage 4 of 5 (IPv6 Configure Timeout) complete.
Jun 26 13:05:12 debiousci pppd[17824]: CHAP authentication succeeded
Jun 26 13:05:12 debiousci pppd[17824]: CHAP authentication succeeded
Jun 26 13:05:12 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/7: signal quality updated (38)
Jun 26 13:05:13 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/7: access technology changed (umts -> hsupa)
Jun 26 13:05:14 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/7: access technology changed (hsupa -> hspa)
Jun 26 13:05:15 debiousci pppd[17824]: Could not determine remote IP address: defaulting to 10.64.64.64
Jun 26 13:05:15 debiousci pppd[17824]: local  IP address 10.240.43.244
Jun 26 13:05:15 debiousci pppd[17824]: remote IP address 10.64.64.64
Jun 26 13:05:15 debiousci pppd[17824]: primary   DNS address 212.52.97.25
Jun 26 13:05:15 debiousci pppd[17824]: secondary DNS address 193.70.152.25
Jun 26 13:05:15 debiousci NetworkManager[2344]: <info> PPP manager(IP Config Get) reply received.
Jun 26 13:05:15 debiousci NetworkManager[2344]: <info> Activation (ttyUSB2) Stage 5 of 5 (IPv4 Configure Commit) scheduled...
Jun 26 13:05:15 debiousci NetworkManager[2344]: <info> Activation (ttyUSB2) Stage 5 of 5 (IPv4 Commit) started...
Jun 26 13:05:15 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/7: signal quality updated (38)
Jun 26 13:05:16 debiousci NetworkManager[2344]: <info> (ttyUSB2): device state change: ip-config -> secondaries (reason 'none') [70 90 0]
Jun 26 13:05:16 debiousci NetworkManager[2344]: <info> Activation (ttyUSB2) Stage 5 of 5 (IPv4 Commit) complete.
Jun 26 13:05:16 debiousci NetworkManager[2344]: <info> (ttyUSB2): device state change: secondaries -> activated (reason 'none') [90 100 0]
Jun 26 13:05:16 debiousci NetworkManager[2344]: <info> NetworkManager state is now CONNECTED_GLOBAL
Jun 26 13:05:16 debiousci NetworkManager[2344]: <info> Policy set 'Wind' (ppp0) as default for IPv4 routing and DNS.
Jun 26 13:05:16 debiousci NetworkManager[2344]: <info> Activation (ttyUSB2) successful, device activated.
Jun 26 13:05:16 debiousci dbus[2302]: [system] Activating service name='org.freedesktop.nm_dispatcher' (using servicehelper)
Jun 26 13:05:16 debiousci dbus[2302]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Jun 26 13:05:16 debiousci pppd[17824]: Protocol-Reject for unsupported protocol 0x19
Jun 26 13:05:24 debiousci ModemManager[4229]: <info>  Modem /org/freedesktop/ModemManager1/Modem/7: signal quality updated (25)
-------------- next part --------------
Kernel IP routing table
Destination     Gateway         Genmask         Flags Metric Ref    Use Iface
0.0.0.0         0.0.0.0         0.0.0.0         U     0      0        0 wwan0
10.0.0.0        0.0.0.0         255.0.0.0       U     7      0        0 wwan0
169.254.0.0     0.0.0.0         255.255.0.0     U     1000   0        0 wwan0
-------------- next part --------------
Kernel IP routing table
Destination     Gateway         Genmask         Flags Metric Ref    Use Iface
0.0.0.0         10.64.64.64     0.0.0.0         UG    0      0        0 ppp0
10.64.64.64     0.0.0.0         255.255.255.255 UH    0      0        0 ppp0
169.254.0.0     0.0.0.0         255.255.0.0     U     1000   0        0 ppp0


More information about the Pkg-utopia-maintainers mailing list