Bug 1281731
| Summary: | USB GSM Modem stopped working after update from Fedora 22 to 23 | ||||||
|---|---|---|---|---|---|---|---|
| Product: | [Fedora] Fedora | Reporter: | Sergey Bostandzhyan <jin> | ||||
| Component: | ModemManager | Assignee: | Lubomir Rintel <lkundrak> | ||||
| Status: | CLOSED EOL | QA Contact: | Fedora Extras Quality Assurance <extras-qa> | ||||
| Severity: | high | Docs Contact: | |||||
| Priority: | unspecified | ||||||
| Version: | 23 | CC: | dcbw, jin, lkundrak, lrintel | ||||
| Target Milestone: | --- | ||||||
| Target Release: | --- | ||||||
| Hardware: | x86_64 | ||||||
| OS: | Linux | ||||||
| Whiteboard: | |||||||
| Fixed In Version: | Doc Type: | Bug Fix | |||||
| Doc Text: | Story Points: | --- | |||||
| Clone Of: | Environment: | ||||||
| Last Closed: | 2016-12-20 15:48:44 UTC | Type: | Bug | ||||
| Regression: | --- | Mount Type: | --- | ||||
| Documentation: | --- | CRM: | |||||
| Verified Versions: | Category: | --- | |||||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |||||
| Cloudforms Team: | --- | Target Upstream Version: | |||||
| Embargoed: | |||||||
| Attachments: |
|
||||||
|
Description
Sergey Bostandzhyan
2015-11-13 10:34:57 UTC
Can you grab the output of: lsusb -v -d 12d1:1446 Wanted to run the above, but noticed one weird thing with the id's.. it presents itself once with product id 1446 and then with product id 1001:
[275910.115189] usb 2-4: new high-speed USB device number 28 using ehci-pci
[275910.232345] usb 2-4: New USB device found, idVendor=12d1, idProduct=1446
[275910.232357] usb 2-4: New USB device strings: Mfr=3, Product=2, SerialNumber=0
[275910.232365] usb 2-4: Product: HUAWEI Mobile
[275910.232372] usb 2-4: Manufacturer: HUAWEI Technology
[275910.234834] usb-storage 2-4:1.0: USB Mass Storage device detected
[275910.235520] scsi host77: usb-storage 2-4:1.0
[275910.235771] usb-storage 2-4:1.1: USB Mass Storage device detected
[275910.235915] scsi host78: usb-storage 2-4:1.1
[275910.797879] usb 2-4: USB disconnect, device number 28
[275914.900175] usb 2-4: new high-speed USB device number 29 using ehci-pci
[275915.016809] usb 2-4: New USB device found, idVendor=12d1, idProduct=1001
[275915.016818] usb 2-4: New USB device strings: Mfr=3, Product=2, SerialNumber=0
[275915.016823] usb 2-4: Product: HUAWEI Mobile
[275915.016828] usb 2-4: Manufacturer: HUAWEI Technology
[275915.019561] usb-storage 2-4:1.0: USB Mass Storage device detected
[275915.019922] option 2-4:1.0: GSM modem (1-port) converter detected
[275915.021190] usb 2-4: GSM modem (1-port) converter now attached to ttyUSB0
[275915.021410] usb-storage 2-4:1.1: USB Mass Storage device detected
[275915.021630] option 2-4:1.1: GSM modem (1-port) converter detected
[275915.021993] usb 2-4: GSM modem (1-port) converter now attached to ttyUSB1
[275915.022204] usb-storage 2-4:1.2: USB Mass Storage device detected
[275915.023113] option 2-4:1.2: GSM modem (1-port) converter detected
[275915.023896] usb 2-4: GSM modem (1-port) converter now attached to ttyUSB2
[275915.024093] usb-storage 2-4:1.3: USB Mass Storage device detected
Anyway, lsusb for 1446 does not return anything, lsusb for 1001 returns:
# lsusb -v -d 12d1:1001
Bus 002 Device 029: ID 12d1:1001 Huawei Technologies Co., Ltd. E169/E620/E800 HSDPA Modem
Device Descriptor:
bLength 18
bDescriptorType 1
bcdUSB 2.00
bDeviceClass 0
bDeviceSubClass 0
bDeviceProtocol 0
bMaxPacketSize0 64
idVendor 0x12d1 Huawei Technologies Co., Ltd.
idProduct 0x1001 E169/E620/E800 HSDPA Modem
bcdDevice 0.00
iManufacturer 3 HUAWEI Technology
iProduct 2 HUAWEI Mobile
iSerial 0
bNumConfigurations 1
Configuration Descriptor:
bLength 9
bDescriptorType 2
wTotalLength 131
bNumInterfaces 5
bConfigurationValue 1
iConfiguration 1 Huawei Configuration
bmAttributes 0xe0
Self Powered
Remote Wakeup
MaxPower 500mA
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 0
bAlternateSetting 0
bNumEndpoints 3
bInterfaceClass 255 Vendor Specific Class
bInterfaceSubClass 255 Vendor Specific Subclass
bInterfaceProtocol 255 Vendor Specific Protocol
iInterface 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x81 EP 1 IN
bmAttributes 3
Transfer Type Interrupt
Synch Type None
Usage Type Data
wMaxPacketSize 0x0040 1x 64 bytes
bInterval 5
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x82 EP 2 IN
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0200 1x 512 bytes
bInterval 32
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x01 EP 1 OUT
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0200 1x 512 bytes
bInterval 32
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 1
bAlternateSetting 0
bNumEndpoints 2
bInterfaceClass 255 Vendor Specific Class
bInterfaceSubClass 255 Vendor Specific Subclass
bInterfaceProtocol 255 Vendor Specific Protocol
iInterface 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x83 EP 3 IN
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0200 1x 512 bytes
bInterval 32
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x02 EP 2 OUT
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0200 1x 512 bytes
bInterval 32
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 2
bAlternateSetting 0
bNumEndpoints 2
bInterfaceClass 255 Vendor Specific Class
bInterfaceSubClass 255 Vendor Specific Subclass
bInterfaceProtocol 255 Vendor Specific Protocol
iInterface 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x84 EP 4 IN
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0200 1x 512 bytes
bInterval 32
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x03 EP 3 OUT
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0200 1x 512 bytes
bInterval 32
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 3
bAlternateSetting 0
bNumEndpoints 2
bInterfaceClass 8 Mass Storage
bInterfaceSubClass 6 SCSI
bInterfaceProtocol 80 Bulk-Only
iInterface 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x85 EP 5 IN
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0200 1x 512 bytes
bInterval 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x04 EP 4 OUT
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0200 1x 512 bytes
bInterval 0
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 4
bAlternateSetting 0
bNumEndpoints 2
bInterfaceClass 8 Mass Storage
bInterfaceSubClass 6 SCSI
bInterfaceProtocol 80 Bulk-Only
iInterface 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x05 EP 5 OUT
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0200 1x 512 bytes
bInterval 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x86 EP 6 IN
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0200 1x 512 bytes
bInterval 0
Device Qualifier (for other device speed):
bLength 10
bDescriptorType 6
bcdUSB 2.00
bDeviceClass 0
bDeviceSubClass 0
bDeviceProtocol 0
bMaxPacketSize0 64
bNumConfigurations 1
can't get debug descriptor: Resource temporarily unavailable
Device Status: 0x0003
Self Powered
Remote Wakeup Enabled
(In reply to Sergey Bostandzhyan from comment #2) > Wanted to run the above, but noticed one weird thing with the id's.. it > presents itself once with product id 1446 and then with product id 1001: It's getting mode-switched from "driver mode" (1446) where it presents a fake CDROM with the drivers on it, to modem mode (1001). USB interface #0 (which corresponds to ttyUSB0) is the actual data port for PPP as shown by the lsusb output (since it has an interrupt endpoint), but it appears that ModemManager is selecting ttyUSB2 for the data port instead. In any case, until MM can better figure out the port layout, try dropping the following into a file in /etc/udev/rules.d/77-huawei-ce0682.rules, and then unplugging and replugging the device: ACTION!="add|change|move", GOTO="mm_huawei_ce0682_port_types_end" SUBSYSTEM!="tty", GOTO="mm_huawei_ce0682_port_types_end" SUBSYSTEMS=="usb", ATTRS{idVendor}=="12d1", GOTO="mm_huawei_ce0682_port_types_vendorcheck" GOTO="mm_huawei_ce0682_port_types_end" LABEL="mm_huawei_ce0682_port_types_vendorcheck" SUBSYSTEMS=="usb", ATTRS{bInterfaceNumber}=="?*", ENV{.MM_USBIFNUM}="$attr{bInterfaceNumber}" ATTRS{idVendor}=="12d1", ATTRS{idProduct}=="1001", ENV{.MM_USBIFNUM}=="00", ENV{ID_MM_HUAWEI_MODEM_PORT}="1" LABEL="mm_huawei_ce0682_port_types_end" OK, but I will only be able to check the connection tomorrow (sim card is for another country, going there tomorrow again). Right now, with the above rules the log of plugging it in looks like this: Nov 13 21:22:11 469.lan kernel: usb 2-4: new high-speed USB device number 34 using ehci-pci Nov 13 21:22:11 469.lan kernel: usb 2-4: New USB device found, idVendor=12d1, idProduct=1446 Nov 13 21:22:11 469.lan kernel: usb 2-4: New USB device strings: Mfr=3, Product=2, SerialNumber=0 Nov 13 21:22:11 469.lan kernel: usb 2-4: Product: HUAWEI Mobile Nov 13 21:22:11 469.lan kernel: usb 2-4: Manufacturer: HUAWEI Technology Nov 13 21:22:11 469.lan kernel: usb-storage 2-4:1.0: USB Mass Storage device detected Nov 13 21:22:11 469.lan kernel: scsi host98: usb-storage 2-4:1.0 Nov 13 21:22:11 469.lan kernel: usb-storage 2-4:1.1: USB Mass Storage device detected Nov 13 21:22:11 469.lan kernel: scsi host99: usb-storage 2-4:1.1 Nov 13 21:22:11 469.lan mtp-probe[8242]: checking bus 2, device 34: "/sys/devices/pci0000:00/0000:00:1d.7/usb2/2-4" Nov 13 21:22:11 469.lan mtp-probe[8242]: bus: 2, device: 34 was not an MTP device Nov 13 21:22:11 469.lan root[8253]: usb_modeswitch: use overriding config file /etc/usb_modeswitch.d/12d1:1446; make sure this is intended Nov 13 21:22:11 469.lan root[8254]: usb_modeswitch: please report any new or corrected settings; otherwise, check for outdated files Nov 13 21:22:11 469.lan usb_modeswitch[8256]: switch device 12d1:1446 on 002/034 Nov 13 21:22:11 469.lan kernel: usb 2-4: USB disconnect, device number 34 Nov 13 21:22:16 469.lan kernel: usb 2-4: new high-speed USB device number 35 using ehci-pci Nov 13 21:22:16 469.lan kernel: usb 2-4: New USB device found, idVendor=12d1, idProduct=1001 Nov 13 21:22:16 469.lan kernel: usb 2-4: New USB device strings: Mfr=3, Product=2, SerialNumber=0 Nov 13 21:22:16 469.lan kernel: usb 2-4: Product: HUAWEI Mobile Nov 13 21:22:16 469.lan kernel: usb 2-4: Manufacturer: HUAWEI Technology Nov 13 21:22:16 469.lan kernel: usb-storage 2-4:1.0: USB Mass Storage device detected Nov 13 21:22:16 469.lan kernel: option 2-4:1.0: GSM modem (1-port) converter detected Nov 13 21:22:16 469.lan kernel: usb 2-4: GSM modem (1-port) converter now attached to ttyUSB0 Nov 13 21:22:16 469.lan kernel: usb-storage 2-4:1.1: USB Mass Storage device detected Nov 13 21:22:16 469.lan kernel: option 2-4:1.1: GSM modem (1-port) converter detected Nov 13 21:22:16 469.lan kernel: usb 2-4: GSM modem (1-port) converter now attached to ttyUSB1 Nov 13 21:22:16 469.lan kernel: usb-storage 2-4:1.2: USB Mass Storage device detected Nov 13 21:22:16 469.lan kernel: option 2-4:1.2: GSM modem (1-port) converter detected Nov 13 21:22:16 469.lan kernel: usb 2-4: GSM modem (1-port) converter now attached to ttyUSB2 Nov 13 21:22:16 469.lan kernel: usb-storage 2-4:1.3: USB Mass Storage device detected Nov 13 21:22:16 469.lan kernel: scsi host103: usb-storage 2-4:1.3 Nov 13 21:22:16 469.lan kernel: usb-storage 2-4:1.4: USB Mass Storage device detected Nov 13 21:22:16 469.lan kernel: scsi host104: usb-storage 2-4:1.4 Nov 13 21:22:17 469.lan root[8270]: usb_modeswitch: switched to 12d1:1001 on 002/035 Nov 13 21:22:17 469.lan kernel: scsi 103:0:0:0: CD-ROM HUAWEI Mass Storage 2.31 PQ: 0 ANSI: 2 Nov 13 21:22:17 469.lan kernel: scsi 104:0:0:0: Direct-Access HUAWEI SD Storage 2.31 PQ: 0 ANSI: 2 Nov 13 21:22:17 469.lan kernel: sr 103:0:0:0: [sr1] scsi-1 drive Nov 13 21:22:17 469.lan kernel: sr 103:0:0:0: Attached scsi CD-ROM sr1 Nov 13 21:22:17 469.lan kernel: sr 103:0:0:0: Attached scsi generic sg3 type 5 Nov 13 21:22:17 469.lan kernel: sd 104:0:0:0: Attached scsi generic sg4 type 0 Nov 13 21:22:17 469.lan kernel: sd 104:0:0:0: [sdc] Attached SCSI removable disk Nov 13 21:22:18 469.lan mtp-probe[8277]: checking bus 2, device 35: "/sys/devices/pci0000:00/0000:00:1d.7/usb2/2-4" Nov 13 21:22:18 469.lan mtp-probe[8277]: bus: 2, device: 35 was not an MTP device Nov 13 21:22:18 469.lan ModemManager[13268]: <warn> (ttyUSB1): port attributes not fully set Nov 13 21:22:18 469.lan ModemManager[13268]: <warn> (ttyUSB2): port attributes not fully set Nov 13 21:22:27 469.lan ModemManager[13268]: <warn> (ttyUSB2): port attributes not fully set Nov 13 21:22:28 469.lan kernel: sd 104:0:0:0: [sdc] 3854336 512-byte logical blocks: (1.97 GB/1.83 GiB) Nov 13 21:22:28 469.lan kernel: sd 104:0:0:0: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA Nov 13 21:22:28 469.lan kernel: sdc: sdc1 sdc2 Nov 13 21:22:30 469.lan ModemManager[13268]: <info> Creating modem with plugin 'Generic' and '3' ports Nov 13 21:22:30 469.lan ModemManager[13268]: <warn> Could not grab port (tty/ttyUSB0): 'Cannot add port 'tty/ttyUSB0', unhandled serial type' Nov 13 21:22:30 469.lan ModemManager[13268]: <warn> (ttyUSB2): port attributes not fully set Nov 13 21:22:30 469.lan ModemManager[13268]: <info> Modem for device at '/sys/devices/pci0000:00/0000:00:1d.7/usb2/2-4' successfully created Nov 13 21:22:30 469.lan ModemManager[13268]: <info> Modem: state changed (unknown -> disabled) Nov 13 21:22:30 469.lan NetworkManager[13343]: <info> (ttyUSB2): modem state changed, 'disabled' --> 'enabling' (reason: user preference) Nov 13 21:22:30 469.lan NetworkManager[13343]: <info> (ttyUSB2): new Broadband device (carrier: UNKNOWN, driver: 'option1', ifindex: 0) Nov 13 21:22:30 469.lan ModemManager[13268]: <info> Modem /org/freedesktop/ModemManager1/Modem/8: state changed (disabled -> enabling) Nov 13 21:22:30 469.lan NetworkManager[13343]: <info> (ttyUSB2): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2] Nov 13 21:22:30 469.lan NetworkManager[13343]: <info> (ttyUSB2): modem state 'enabling' Nov 13 21:22:30 469.lan NetworkManager[13343]: <info> (ttyUSB2): device state change: unavailable -> disconnected (reason 'none') [20 30 0] Nov 13 21:22:30 469.lan ModemManager[13268]: <warn> (ttyUSB2): port attributes not fully set Nov 13 21:22:31 469.lan ModemManager[13268]: <info> Modem /org/freedesktop/ModemManager1/Modem/8: 3GPP Registration state changed (unknown -> registering) Nov 13 21:22:31 469.lan ModemManager[13268]: <info> Modem /org/freedesktop/ModemManager1/Modem/8: 3GPP Registration state changed (registering -> roaming) Nov 13 21:22:31 469.lan ModemManager[13268]: <info> Modem /org/freedesktop/ModemManager1/Modem/8: state changed (enabling -> registered) Nov 13 21:22:31 469.lan NetworkManager[13343]: <info> (ttyUSB2): modem state changed, 'enabling' --> 'registered' (reason: user-requested) By the way I noticed the lines: Nov 13 21:22:11 469.lan root[8253]: usb_modeswitch: use overriding config file /etc/usb_modeswitch.d/12d1:1446; make sure this is intended Nov 13 21:22:11 469.lan root[8254]: usb_modeswitch: please report any new or corrected settings; otherwise, check for outdated files Can the problem be related to that? Probably unrelated. I forgot one thing: sudo udevadm control --reload which will actually make udev aware of the new rules. Can you run that command and then unplug/replug and see what NetworkManager says the control port is again? I used udevadm control --reload-rules before generating the above log, I repeated it now with --reload and the log looks pretty much the same. I had the impression that the rule did not really work out since its still referring to /dev/ttyUSB2? OK, so tried connecting with the udev rules in place, tested after a clean boot. Unfortunately it still did not work... the logs are below. Connecting first time after inserting modem: Dec 27 00:06:22 469.lan kernel: usb 2-4: new high-speed USB device number 8 using ehci-pci Dec 27 00:06:22 469.lan kernel: usb 2-4: New USB device found, idVendor=12d1, idProduct=1446 Dec 27 00:06:22 469.lan kernel: usb 2-4: New USB device strings: Mfr=3, Product=2, SerialNumber=0 Dec 27 00:06:22 469.lan kernel: usb 2-4: Product: HUAWEI Mobile Dec 27 00:06:22 469.lan kernel: usb 2-4: Manufacturer: HUAWEI Technology Dec 27 00:06:22 469.lan kernel: usb-storage 2-4:1.0: USB Mass Storage device detected Dec 27 00:06:22 469.lan kernel: scsi host19: usb-storage 2-4:1.0 Dec 27 00:06:22 469.lan kernel: usb-storage 2-4:1.1: USB Mass Storage device detected Dec 27 00:06:22 469.lan kernel: scsi host20: usb-storage 2-4:1.1 Dec 27 00:06:22 469.lan mtp-probe[3681]: checking bus 2, device 8: "/sys/devices/pci0000:00/0000:00:1d.7/usb2/2-4" Dec 27 00:06:22 469.lan mtp-probe[3681]: bus: 2, device: 8 was not an MTP device Dec 27 00:06:23 469.lan root[3693]: usb_modeswitch: use overriding config file /etc/usb_modeswitch.d/12d1:1446; make sure this is intended Dec 27 00:06:23 469.lan root[3694]: usb_modeswitch: please report any new or corrected settings; otherwise, check for outdated files Dec 27 00:06:23 469.lan usb_modeswitch[3696]: switch device 12d1:1446 on 002/008 Dec 27 00:06:23 469.lan kernel: usb 2-4: USB disconnect, device number 8 Dec 27 00:06:27 469.lan kernel: usb 2-4: new high-speed USB device number 9 using ehci-pci Dec 27 00:06:27 469.lan kernel: usb 2-4: New USB device found, idVendor=12d1, idProduct=1001 Dec 27 00:06:27 469.lan kernel: usb 2-4: New USB device strings: Mfr=3, Product=2, SerialNumber=0 Dec 27 00:06:27 469.lan kernel: usb 2-4: Product: HUAWEI Mobile Dec 27 00:06:27 469.lan kernel: usb 2-4: Manufacturer: HUAWEI Technology Dec 27 00:06:27 469.lan kernel: usb-storage 2-4:1.0: USB Mass Storage device detected Dec 27 00:06:27 469.lan kernel: option 2-4:1.0: GSM modem (1-port) converter detected Dec 27 00:06:27 469.lan kernel: usb 2-4: GSM modem (1-port) converter now attached to ttyUSB0 Dec 27 00:06:27 469.lan kernel: usb-storage 2-4:1.1: USB Mass Storage device detected Dec 27 00:06:27 469.lan kernel: option 2-4:1.1: GSM modem (1-port) converter detected Dec 27 00:06:27 469.lan kernel: usb 2-4: GSM modem (1-port) converter now attached to ttyUSB1 Dec 27 00:06:27 469.lan kernel: usb-storage 2-4:1.2: USB Mass Storage device detected Dec 27 00:06:27 469.lan kernel: option 2-4:1.2: GSM modem (1-port) converter detected Dec 27 00:06:27 469.lan kernel: usb 2-4: GSM modem (1-port) converter now attached to ttyUSB2 Dec 27 00:06:27 469.lan kernel: usb-storage 2-4:1.3: USB Mass Storage device detected Dec 27 00:06:27 469.lan kernel: scsi host24: usb-storage 2-4:1.3 Dec 27 00:06:27 469.lan kernel: usb-storage 2-4:1.4: USB Mass Storage device detected Dec 27 00:06:27 469.lan kernel: scsi host25: usb-storage 2-4:1.4 Dec 27 00:06:28 469.lan root[3714]: usb_modeswitch: switched to 12d1:1001 on 002/009 Dec 27 00:06:28 469.lan kernel: scsi 24:0:0:0: CD-ROM HUAWEI Mass Storage 2.31 PQ: 0 ANSI: 2 Dec 27 00:06:28 469.lan kernel: scsi 25:0:0:0: Direct-Access HUAWEI SD Storage 2.31 PQ: 0 ANSI: 2 Dec 27 00:06:28 469.lan kernel: sr 24:0:0:0: [sr1] scsi-1 drive Dec 27 00:06:28 469.lan kernel: sr 24:0:0:0: Attached scsi CD-ROM sr1 Dec 27 00:06:28 469.lan kernel: sr 24:0:0:0: Attached scsi generic sg3 type 5 Dec 27 00:06:28 469.lan kernel: sd 25:0:0:0: Attached scsi generic sg4 type 0 Dec 27 00:06:28 469.lan kernel: sd 25:0:0:0: [sdc] Attached SCSI removable disk Dec 27 00:06:30 469.lan mtp-probe[3722]: checking bus 2, device 9: "/sys/devices/pci0000:00/0000:00:1d.7/usb2/2-4" Dec 27 00:06:30 469.lan mtp-probe[3722]: bus: 2, device: 9 was not an MTP device Dec 27 00:06:30 469.lan ModemManager[1156]: <warn> (ttyUSB1): port attributes not fully set Dec 27 00:06:30 469.lan ModemManager[1156]: <warn> (ttyUSB2): port attributes not fully set Dec 27 00:06:38 469.lan ModemManager[1156]: <warn> (ttyUSB2): port attributes not fully set Dec 27 00:06:40 469.lan kernel: sd 25:0:0:0: [sdc] 3854336 512-byte logical blocks: (1.97 GB/1.83 GiB) Dec 27 00:06:40 469.lan kernel: sd 25:0:0:0: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA Dec 27 00:06:40 469.lan kernel: sdc: sdc1 sdc2 Dec 27 00:06:41 469.lan ModemManager[1156]: <info> Creating modem with plugin 'Generic' and '3' ports Dec 27 00:06:41 469.lan ModemManager[1156]: <warn> Could not grab port (tty/ttyUSB0): 'Cannot add port 'tty/ttyUSB0', unhandled serial type' Dec 27 00:06:41 469.lan ModemManager[1156]: <warn> (ttyUSB2): port attributes not fully set Dec 27 00:06:41 469.lan ModemManager[1156]: <info> Modem for device at '/sys/devices/pci0000:00/0000:00:1d.7/usb2/2-4' successfully created Dec 27 00:06:42 469.lan ModemManager[1156]: <info> Modem: state changed (unknown -> disabled) Dec 27 00:06:42 469.lan NetworkManager[1380]: <info> (ttyUSB2): modem state changed, 'disabled' --> 'enabling' (reason: user preference) Dec 27 00:06:42 469.lan NetworkManager[1380]: <info> (ttyUSB2): new Broadband device (carrier: UNKNOWN, driver: 'option1', ifindex: 0) Dec 27 00:06:42 469.lan NetworkManager[1380]: <info> (ttyUSB2): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2] Dec 27 00:06:42 469.lan NetworkManager[1380]: <info> (ttyUSB2): modem state 'enabling' Dec 27 00:06:42 469.lan NetworkManager[1380]: <info> (ttyUSB2): device state change: unavailable -> disconnected (reason 'none') [20 30 0] Dec 27 00:06:42 469.lan ModemManager[1156]: <info> Modem /org/freedesktop/ModemManager1/Modem/2: state changed (disabled -> enabling) Dec 27 00:06:42 469.lan ModemManager[1156]: <warn> (ttyUSB2): port attributes not fully set Dec 27 00:06:42 469.lan ModemManager[1156]: <info> Modem /org/freedesktop/ModemManager1/Modem/2: 3GPP Registration state changed (unknown -> registering) Dec 27 00:06:42 469.lan ModemManager[1156]: <info> Modem /org/freedesktop/ModemManager1/Modem/2: 3GPP Registration state changed (registering -> roaming) Dec 27 00:06:43 469.lan ModemManager[1156]: <info> Modem /org/freedesktop/ModemManager1/Modem/2: state changed (enabling -> registered) Dec 27 00:06:43 469.lan NetworkManager[1380]: <info> (ttyUSB2): modem state changed, 'enabling' --> 'registered' (reason: user-requested) Connecting again: Dec 27 00:08:01 469.lan NetworkManager[1380]: <info> (ttyUSB2): Activation: starting connection 'HoT' (ed6847e9-9691-42b5-981b-d907db8c1e1c) Dec 27 00:08:01 469.lan NetworkManager[1380]: <info> (ttyUSB2): device state change: disconnected -> prepare (reason 'none') [30 40 0] Dec 27 00:08:01 469.lan NetworkManager[1380]: <info> NetworkManager state is now CONNECTING Dec 27 00:08:01 469.lan ModemManager[1156]: <info> Simple connect started... Dec 27 00:08:01 469.lan ModemManager[1156]: <info> Simple connect state (4/8): Wait to get fully enabled Dec 27 00:08:01 469.lan ModemManager[1156]: <info> Simple connect state (5/8): Register Dec 27 00:08:01 469.lan ModemManager[1156]: <info> Simple connect state (6/8): Bearer Dec 27 00:08:01 469.lan ModemManager[1156]: <info> Simple connect state (7/8): Connect Dec 27 00:08:01 469.lan ModemManager[1156]: <info> Modem /org/freedesktop/ModemManager1/Modem/2: state changed (registered -> connecting) Dec 27 00:08:01 469.lan NetworkManager[1380]: <info> (ttyUSB2): modem state changed, 'registered' --> 'connecting' (reason: user-requested) Dec 27 00:08:01 469.lan ModemManager[1156]: <info> Modem /org/freedesktop/ModemManager1/Modem/2: state changed (connecting -> connected) Dec 27 00:08:01 469.lan ModemManager[1156]: <info> Simple connect state (8/8): All done Dec 27 00:08:01 469.lan NetworkManager[1380]: <info> (ttyUSB2): modem state changed, 'connecting' --> 'connected' (reason: user-requested) Dec 27 00:08:01 469.lan NetworkManager[1380]: <warn> (ttyUSB2): failed to look up interface index Dec 27 00:08:01 469.lan NetworkManager[1380]: <info> (ttyUSB2): device state change: prepare -> config (reason 'none') [40 50 0] Dec 27 00:08:01 469.lan audit: NETFILTER_CFG table=filter family=2 entries=82 Dec 27 00:08:01 469.lan audit[3839]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=55b14cc6e930 items=0 ppid=1150 pid=3839 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:01 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4900494E5055545F5A4F4E45530031002D740066696C746572002D690074747955534232002D6700494E5F7075626C6963 Dec 27 00:08:01 469.lan audit: NETFILTER_CFG table=filter family=10 entries=83 Dec 27 00:08:01 469.lan audit[3840]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=55d65e4cc7d0 items=0 ppid=1150 pid=3840 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:01 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4900494E5055545F5A4F4E45530031002D740066696C746572002D690074747955534232002D6700494E5F7075626C6963 Dec 27 00:08:01 469.lan audit: NETFILTER_CFG table=filter family=2 entries=83 Dec 27 00:08:01 469.lan audit[3841]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=559b5a3ccaa0 items=0 ppid=1150 pid=3841 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:01 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4900464F52574152445F4F55545F5A4F4E45530031002D740066696C746572002D6F0074747955534232002D67004657444F5F7075626C6963 Dec 27 00:08:01 469.lan audit: NETFILTER_CFG table=filter family=10 entries=84 Dec 27 00:08:01 469.lan audit[3842]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=55e2192b79c0 items=0 ppid=1150 pid=3842 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:01 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4900464F52574152445F4F55545F5A4F4E45530031002D740066696C746572002D6F0074747955534232002D67004657444F5F7075626C6963 Dec 27 00:08:01 469.lan audit: NETFILTER_CFG table=filter family=2 entries=84 Dec 27 00:08:01 469.lan audit[3843]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=55753c88fc20 items=0 ppid=1150 pid=3843 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:01 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4900464F52574152445F494E5F5A4F4E45530031002D740066696C746572002D690074747955534232002D6700465744495F7075626C6963 Dec 27 00:08:01 469.lan audit: NETFILTER_CFG table=filter family=10 entries=85 Dec 27 00:08:01 469.lan audit[3844]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=55a7f602fbb0 items=0 ppid=1150 pid=3844 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:01 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4900464F52574152445F494E5F5A4F4E45530031002D740066696C746572002D690074747955534232002D6700465744495F7075626C6963 Dec 27 00:08:01 469.lan audit: NETFILTER_CFG table=nat family=2 entries=50 Dec 27 00:08:01 469.lan audit[3845]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=55c923d63030 items=0 ppid=1150 pid=3845 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:01 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4900504F5354524F5554494E475F5A4F4E45530031002D74006E6174002D6F0074747955534232002D6700504F53545F7075626C6963 Dec 27 00:08:01 469.lan audit: NETFILTER_CFG table=nat family=10 entries=50 Dec 27 00:08:01 469.lan audit[3846]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=55aec602ff50 items=0 ppid=1150 pid=3846 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:01 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4900504F5354524F5554494E475F5A4F4E45530031002D74006E6174002D6F0074747955534232002D6700504F53545F7075626C6963 Dec 27 00:08:01 469.lan audit: NETFILTER_CFG table=nat family=2 entries=51 Dec 27 00:08:01 469.lan audit[3847]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=5642ae31b1b0 items=0 ppid=1150 pid=3847 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:01 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4900505245524F5554494E475F5A4F4E45530031002D74006E6174002D690074747955534232002D67005052455F7075626C6963 Dec 27 00:08:01 469.lan audit: NETFILTER_CFG table=nat family=10 entries=51 Dec 27 00:08:01 469.lan audit[3848]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=55e970bfe140 items=0 ppid=1150 pid=3848 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:01 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4900505245524F5554494E475F5A4F4E45530031002D74006E6174002D690074747955534232002D67005052455F7075626C6963 Dec 27 00:08:01 469.lan audit: NETFILTER_CFG table=mangle family=2 entries=39 Dec 27 00:08:01 469.lan audit[3849]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=55aff321e420 items=0 ppid=1150 pid=3849 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:01 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4900505245524F5554494E475F5A4F4E45530031002D74006D616E676C65002D690074747955534232002D67005052455F7075626C6963 Dec 27 00:08:01 469.lan audit: NETFILTER_CFG table=mangle family=10 entries=39 Dec 27 00:08:01 469.lan audit[3850]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=56340b039fd0 items=0 ppid=1150 pid=3850 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:01 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4900505245524F5554494E475F5A4F4E45530031002D74006D616E676C65002D690074747955534232002D67005052455F7075626C6963 Dec 27 00:08:01 469.lan NetworkManager[1380]: <info> (ttyUSB2): device state change: config -> ip-config (reason 'none') [50 70 0] Dec 27 00:08:01 469.lan NetworkManager[1380]: <warn> (ttyUSB2): interface ttyUSB2 not up for IP configuration Dec 27 00:08:01 469.lan NetworkManager[1380]: <info> (ttyUSB2): using modem-specified IP timeout: 20 seconds Dec 27 00:08:01 469.lan NetworkManager[1380]: <info> starting PPP connection Dec 27 00:08:01 469.lan NetworkManager[1380]: <info> pppd started with pid 3851 Dec 27 00:08:01 469.lan NetworkManager[1380]: <info> (ttyUSB2): IPv6 configuration disabled Dec 27 00:08:01 469.lan pppd[3851]: Plugin /usr/lib64/pppd/2.4.7/nm-pppd-plugin.so loaded. Dec 27 00:08:01 469.lan NetworkManager[1380]: Plugin /usr/lib64/pppd/2.4.7/nm-pppd-plugin.so loaded. Dec 27 00:08:01 469.lan NetworkManager[1380]: nm-pppd-plugin-Message: nm-ppp-plugin: (plugin_init): initializing Dec 27 00:08:01 469.lan pppd[3851]: pppd 2.4.7 started by root, uid 0 Dec 27 00:08:01 469.lan pppd[3851]: Removed stale lock on ttyUSB2 (pid 3196) Dec 27 00:08:01 469.lan NetworkManager[1380]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_phasechange): status 3 / phase 'serial connection' Dec 27 00:08:01 469.lan NetworkManager[1380]: Removed stale lock on ttyUSB2 (pid 3196) Dec 27 00:08:01 469.lan pppd[3851]: Using interface ppp0 Dec 27 00:08:01 469.lan pppd[3851]: Connect: ppp0 <--> /dev/ttyUSB2 Dec 27 00:08:01 469.lan NetworkManager[1380]: <info> (ppp0): new Generic device (carrier: UNKNOWN, driver: 'unknown', ifindex: 5) Dec 27 00:08:01 469.lan NetworkManager[1380]: Using interface ppp0 Dec 27 00:08:01 469.lan NetworkManager[1380]: Connect: ppp0 <--> /dev/ttyUSB2 Dec 27 00:08:01 469.lan NetworkManager[1380]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_phasechange): status 5 / phase 'establish' Dec 27 00:08:21 469.lan NetworkManager[1380]: <warn> pppd timed out or didn't initialize our dbus module Dec 27 00:08:21 469.lan NetworkManager[1380]: <info> (ttyUSB2): device state change: ip-config -> failed (reason 'ip-config-unavailable') [70 120 5] Dec 27 00:08:21 469.lan NetworkManager[1380]: <info> NetworkManager state is now DISCONNECTED Dec 27 00:08:21 469.lan NetworkManager[1380]: <warn> (ttyUSB2): Activation: failed for connection 'HoT' Dec 27 00:08:21 469.lan NetworkManager[1380]: <info> (ttyUSB2): device state change: failed -> disconnected (reason 'none') [120 30 0] Dec 27 00:08:21 469.lan pppd[3851]: Terminating on signal 15 Dec 27 00:08:21 469.lan NetworkManager[1380]: Terminating on signal 15 Dec 27 00:08:21 469.lan NetworkManager[1380]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_phasechange): status 10 / phase 'terminate' Dec 27 00:08:21 469.lan dbus[1160]: [system] Rejected send message, 9 matched rules; type="error", sender=":1.10" (uid=0 pid=1380 comm="/usr/sbin/NetworkManager --no-daemon ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.60" (uid=0 pid=3851 comm="/usr/sbin/pppd nodetach lock nodefaultroute ipv6 ,") Dec 27 00:08:21 469.lan ModemManager[1156]: <info> Modem /org/freedesktop/ModemManager1/Modem/2: state changed (connected -> disconnecting) Dec 27 00:08:21 469.lan NetworkManager[1380]: <info> (ttyUSB2): modem state changed, 'connected' --> 'disconnecting' (reason: user-requested) Dec 27 00:08:21 469.lan audit: NETFILTER_CFG table=filter family=2 entries=85 Dec 27 00:08:21 469.lan audit[3883]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=55720c552be0 items=0 ppid=1150 pid=3883 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:21 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4400494E5055545F5A4F4E4553002D740066696C746572002D690074747955534232002D6700494E5F7075626C6963 Dec 27 00:08:21 469.lan audit: NETFILTER_CFG table=filter family=10 entries=86 Dec 27 00:08:21 469.lan audit[3884]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=558f4e530b70 items=0 ppid=1150 pid=3884 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:21 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4400494E5055545F5A4F4E4553002D740066696C746572002D690074747955534232002D6700494E5F7075626C6963 Dec 27 00:08:21 469.lan audit: NETFILTER_CFG table=filter family=2 entries=84 Dec 27 00:08:21 469.lan audit[3885]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=563dc6478a70 items=0 ppid=1150 pid=3885 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:21 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4400464F52574152445F4F55545F5A4F4E4553002D740066696C746572002D6F0074747955534232002D67004657444F5F7075626C6963 Dec 27 00:08:21 469.lan audit: NETFILTER_CFG table=filter family=10 entries=85 Dec 27 00:08:21 469.lan audit[3886]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=55e28b418980 items=0 ppid=1150 pid=3886 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:21 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4400464F52574152445F4F55545F5A4F4E4553002D740066696C746572002D6F0074747955534232002D67004657444F5F7075626C6963 Dec 27 00:08:21 469.lan audit: NETFILTER_CFG table=filter family=2 entries=83 Dec 27 00:08:21 469.lan audit[3887]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=561aa01d48f0 items=0 ppid=1150 pid=3887 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:21 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4400464F52574152445F494E5F5A4F4E4553002D740066696C746572002D690074747955534232002D6700465744495F7075626C6963 Dec 27 00:08:21 469.lan audit: NETFILTER_CFG table=filter family=10 entries=84 Dec 27 00:08:21 469.lan audit[3888]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=555f7d33e790 items=0 ppid=1150 pid=3888 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:21 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4400464F52574152445F494E5F5A4F4E4553002D740066696C746572002D690074747955534232002D6700465744495F7075626C6963 Dec 27 00:08:21 469.lan audit: NETFILTER_CFG table=nat family=2 entries=52 Dec 27 00:08:21 469.lan audit[3889]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=56191dd9a170 items=0 ppid=1150 pid=3889 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:21 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4400504F5354524F5554494E475F5A4F4E4553002D74006E6174002D6F0074747955534232002D6700504F53545F7075626C6963 Dec 27 00:08:21 469.lan audit: NETFILTER_CFG table=nat family=10 entries=52 Dec 27 00:08:21 469.lan audit[3890]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=557603b85100 items=0 ppid=1150 pid=3890 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:21 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4400504F5354524F5554494E475F5A4F4E4553002D74006E6174002D6F0074747955534232002D6700504F53545F7075626C6963 Dec 27 00:08:21 469.lan audit: NETFILTER_CFG table=nat family=2 entries=51 Dec 27 00:08:21 469.lan audit[3891]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=5564501ab000 items=0 ppid=1150 pid=3891 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:21 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4400505245524F5554494E475F5A4F4E4553002D74006E6174002D690074747955534232002D67005052455F7075626C6963 Dec 27 00:08:21 469.lan audit: NETFILTER_CFG table=nat family=10 entries=51 Dec 27 00:08:21 469.lan audit[3892]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=55dc0a49ff10 items=0 ppid=1150 pid=3892 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:21 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4400505245524F5554494E475F5A4F4E4553002D74006E6174002D690074747955534232002D67005052455F7075626C6963 Dec 27 00:08:21 469.lan audit: NETFILTER_CFG table=mangle family=2 entries=40 Dec 27 00:08:21 469.lan audit[3893]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=55d330e113e0 items=0 ppid=1150 pid=3893 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:21 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4400505245524F5554494E475F5A4F4E4553002D74006D616E676C65002D690074747955534232002D67005052455F7075626C6963 Dec 27 00:08:21 469.lan audit: NETFILTER_CFG table=mangle family=10 entries=40 Dec 27 00:08:21 469.lan audit[3894]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=564d2594ff90 items=0 ppid=1150 pid=3894 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Dec 27 00:08:21 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4400505245524F5554494E475F5A4F4E4553002D74006D616E676C65002D690074747955534232002D67005052455F7075626C6963 Dec 27 00:08:22 469.lan ModemManager[1156]: <warn> (ttyUSB2): port attributes not fully set Dec 27 00:08:23 469.lan NetworkManager[1380]: <warn> (ppp0): failed to disable userspace IPv6LL address handling Dec 27 00:08:44 469.lan ModemManager[1156]: <info> Modem /org/freedesktop/ModemManager1/Modem/2: state changed (disconnecting -> registered) Dec 27 00:08:44 469.lan NetworkManager[1380]: <info> (ttyUSB2): modem state changed, 'disconnecting' --> 'registered' (reason: user-requested) Another attempt: Dec 27 00:09:01 469.lan NetworkManager[1380]: <info> (ttyUSB2): Activation: starting connection 'HoT' (ed6847e9-9691-42b5-981b-d907db8c1e1c) Dec 27 00:09:01 469.lan NetworkManager[1380]: <info> (ttyUSB2): device state change: disconnected -> prepare (reason 'none') [30 40 0] Dec 27 00:09:01 469.lan NetworkManager[1380]: <info> NetworkManager state is now CONNECTING Dec 27 00:09:01 469.lan ModemManager[1156]: <info> Simple connect started... Dec 27 00:09:01 469.lan ModemManager[1156]: <info> Simple connect state (4/8): Wait to get fully enabled Dec 27 00:09:01 469.lan ModemManager[1156]: <info> Simple connect state (5/8): Register Dec 27 00:09:01 469.lan ModemManager[1156]: <info> Simple connect state (6/8): Bearer Dec 27 00:09:01 469.lan ModemManager[1156]: <info> Simple connect state (7/8): Connect Dec 27 00:09:01 469.lan ModemManager[1156]: <info> Modem /org/freedesktop/ModemManager1/Modem/2: state changed (registered -> connecting) Dec 27 00:09:01 469.lan NetworkManager[1380]: <info> (ttyUSB2): modem state changed, 'registered' --> 'connecting' (reason: user-requested) Dec 27 00:09:02 469.lan kernel: perf interrupt took too long (2511 > 2500), lowering kernel.perf_event_max_sample_rate to 50000 Dec 27 00:09:08 469.lan ModemManager[1156]: <warn> Couldn't initialize PDP context with our APN: 'Sending command failed: 'Resource temporarily unavailable'' Dec 27 00:09:08 469.lan ModemManager[1156]: <info> Modem /org/freedesktop/ModemManager1/Modem/2: state changed (connecting -> registered) Dec 27 00:09:08 469.lan NetworkManager[1380]: <info> (ttyUSB2): modem state changed, 'connecting' --> 'registered' (reason: user-requested) Dec 27 00:09:08 469.lan ModemManager[1156]: <info> Simple connect started... Dec 27 00:09:08 469.lan ModemManager[1156]: <info> Simple connect state (4/8): Wait to get fully enabled Dec 27 00:09:08 469.lan ModemManager[1156]: <info> Simple connect state (5/8): Register Dec 27 00:09:08 469.lan ModemManager[1156]: <info> Simple connect state (6/8): Bearer Dec 27 00:09:08 469.lan ModemManager[1156]: <info> Simple connect state (7/8): Connect Dec 27 00:09:08 469.lan ModemManager[1156]: <info> Modem /org/freedesktop/ModemManager1/Modem/2: state changed (registered -> connecting) Dec 27 00:09:08 469.lan NetworkManager[1380]: <info> (ttyUSB2): modem state changed, 'registered' --> 'connecting' (reason: user-requested) Dec 27 00:09:15 469.lan ModemManager[1156]: <warn> Couldn't initialize PDP context with our APN: 'Sending command failed: 'Resource temporarily unavailable'' Dec 27 00:09:15 469.lan ModemManager[1156]: <info> Modem /org/freedesktop/ModemManager1/Modem/2: state changed (connecting -> registered) Dec 27 00:09:15 469.lan NetworkManager[1380]: <info> (ttyUSB2): modem state changed, 'connecting' --> 'registered' (reason: user-requested) Dec 27 00:09:15 469.lan NetworkManager[1380]: <warn> (ttyUSB2): failed to connect modem: Sending command failed: 'Resource temporarily unavailable' Dec 27 00:09:15 469.lan NetworkManager[1380]: <info> (ttyUSB2): device state change: prepare -> failed (reason 'unknown') [40 120 1] Dec 27 00:09:15 469.lan NetworkManager[1380]: <info> NetworkManager state is now DISCONNECTED Dec 27 00:09:15 469.lan NetworkManager[1380]: <warn> (ttyUSB2): Activation: failed for connection 'HoT' Dec 27 00:09:15 469.lan NetworkManager[1380]: <info> (ttyUSB2): device state change: failed -> disconnected (reason 'none') [120 30 0] Dec 27 00:09:15 469.lan /firewalld[1150]: 2006-12-27 00:09:15 ERROR: UNKNOWN_INTERFACE: 'ttyUSB2' is not in any zone Disalbed firewalld, reconnecting: Dec 27 00:11:36 469.lan NetworkManager[1380]: <info> (ttyUSB2): Activation: starting connection 'HoT' (ed6847e9-9691-42b5-981b-d907db8c1e1c) Dec 27 00:11:36 469.lan NetworkManager[1380]: <info> (ttyUSB2): device state change: disconnected -> prepare (reason 'none') [30 40 0] Dec 27 00:11:36 469.lan NetworkManager[1380]: <info> NetworkManager state is now CONNECTING Dec 27 00:11:36 469.lan ModemManager[1156]: <info> Simple connect started... Dec 27 00:11:36 469.lan ModemManager[1156]: <info> Simple connect state (4/8): Wait to get fully enabled Dec 27 00:11:36 469.lan ModemManager[1156]: <info> Simple connect state (5/8): Register Dec 27 00:11:36 469.lan ModemManager[1156]: <info> Simple connect state (6/8): Bearer Dec 27 00:11:36 469.lan ModemManager[1156]: <info> Simple connect state (7/8): Connect Dec 27 00:11:36 469.lan ModemManager[1156]: <info> Modem /org/freedesktop/ModemManager1/Modem/2: state changed (registered -> connecting) Dec 27 00:11:36 469.lan NetworkManager[1380]: <info> (ttyUSB2): modem state changed, 'registered' --> 'connecting' (reason: user-requested) Dec 27 00:11:43 469.lan ModemManager[1156]: <warn> Couldn't initialize PDP context with our APN: 'Sending command failed: 'Resource temporarily unavailable'' Dec 27 00:11:43 469.lan ModemManager[1156]: <info> Modem /org/freedesktop/ModemManager1/Modem/2: state changed (connecting -> registered) Dec 27 00:11:43 469.lan NetworkManager[1380]: <info> (ttyUSB2): modem state changed, 'connecting' --> 'registered' (reason: user-requested) Dec 27 00:11:43 469.lan ModemManager[1156]: <info> Simple connect started... Dec 27 00:11:43 469.lan ModemManager[1156]: <info> Simple connect state (4/8): Wait to get fully enabled Dec 27 00:11:43 469.lan ModemManager[1156]: <info> Simple connect state (5/8): Register Dec 27 00:11:43 469.lan ModemManager[1156]: <info> Simple connect state (6/8): Bearer Dec 27 00:11:43 469.lan ModemManager[1156]: <info> Simple connect state (7/8): Connect Dec 27 00:11:43 469.lan ModemManager[1156]: <info> Modem /org/freedesktop/ModemManager1/Modem/2: state changed (registered -> connecting) Dec 27 00:11:43 469.lan NetworkManager[1380]: <info> (ttyUSB2): modem state changed, 'registered' --> 'connecting' (reason: user-requested) Dec 27 00:11:58 469.lan ModemManager[1156]: <warn> Couldn't initialize PDP context with our APN: 'Sending command failed: 'Resource temporarily unavailable'' Dec 27 00:11:58 469.lan ModemManager[1156]: <info> Modem /org/freedesktop/ModemManager1/Modem/2: state changed (connecting -> registered) Dec 27 00:11:58 469.lan NetworkManager[1380]: <info> (ttyUSB2): modem state changed, 'connecting' --> 'registered' (reason: user-requested) Dec 27 00:11:58 469.lan NetworkManager[1380]: <warn> (ttyUSB2): failed to connect modem: Sending command failed: 'Resource temporarily unavailable' Dec 27 00:11:58 469.lan NetworkManager[1380]: <info> (ttyUSB2): device state change: prepare -> failed (reason 'unknown') [40 120 1] Dec 27 00:11:58 469.lan NetworkManager[1380]: <info> NetworkManager state is now DISCONNECTED Dec 27 00:11:58 469.lan NetworkManager[1380]: <info> Disabling autoconnect for connection 'HoT'. Dec 27 00:11:58 469.lan NetworkManager[1380]: <warn> (ttyUSB2): Activation: failed for connection 'HoT' Dec 27 00:11:58 469.lan NetworkManager[1380]: <info> (ttyUSB2): device state change: failed -> disconnected (reason 'none') [120 30 0] I made an interesting observation: today I bought a USB hub and wanted to test it, the closest USB device at hand was the modem. Surprisingly, when the modem was plugged into the USB hub I could connect to the internet via NetworkManager without any problems. After that I did another test and plugged the modem directly into the notebook and then the internet connection was failing as described in the bug report. Let me know if you need any logs of that or any further info. What ttyUSBx interface was used for the connection when the device was plugged into the hub? Sorry, I did not realize that my reply was not posted correctly, actually I answered you the same day, but it seems something went wrong, either in my firefox/connection or in bugzilla. Anyway. Back then, when I was testing with the USB hub I wanted to recheck regarding what interface was used, to answer your question. To my surprise - it did not work anymore, also not via the hub, this is what I posted back then (the post that got lost). After I noticed that my answer did not make it to bugzilla I did a retest just now and here are my findings: the hub itself is not really related to the issue or to the solution, the whole thing is really strange. I pugged in the modem directly to the notebook and I could immediately go online without any problems via the network manager. I disconnected/connected a couple of times via the NM menu and it all worked just fine. And here comes the confusing part: I then unplugged the modem and connected it again at a different USB port - the internet connection did not work anymore. I plugged it back in to the other port where it initially worked - and it also failed there. I guess if I did a fresh boot I'd probably have a one time success again. I captured the logs. First, plugging in and connecting successfully: Jan 04 00:02:39 469.lan kernel: usb 1-4: new high-speed USB device number 5 using ehci-pci Jan 04 00:02:39 469.lan kernel: usb 1-4: New USB device found, idVendor=12d1, idProduct=1446 Jan 04 00:02:39 469.lan kernel: usb 1-4: New USB device strings: Mfr=3, Product=2, SerialNumber=0 Jan 04 00:02:39 469.lan kernel: usb 1-4: Product: HUAWEI Mobile Jan 04 00:02:39 469.lan kernel: usb 1-4: Manufacturer: HUAWEI Technology Jan 04 00:02:39 469.lan kernel: usb-storage 1-4:1.0: USB Mass Storage device detected Jan 04 00:02:39 469.lan kernel: scsi host33: usb-storage 1-4:1.0 Jan 04 00:02:39 469.lan kernel: usb-storage 1-4:1.1: USB Mass Storage device detected Jan 04 00:02:39 469.lan kernel: scsi host34: usb-storage 1-4:1.1 Jan 04 00:02:39 469.lan mtp-probe[23434]: checking bus 1, device 5: "/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4" Jan 04 00:02:39 469.lan mtp-probe[23434]: bus: 1, device: 5 was not an MTP device Jan 04 00:02:40 469.lan root[23456]: usb_modeswitch: use overriding config file /etc/usb_modeswitch.d/12d1:1446; make sure this is intended Jan 04 00:02:40 469.lan root[23457]: usb_modeswitch: please report any new or corrected settings; otherwise, check for outdated files Jan 04 00:02:40 469.lan usb_modeswitch[23459]: switch device 12d1:1446 on 001/005 Jan 04 00:02:40 469.lan kernel: usb 1-4: USB disconnect, device number 5 Jan 04 00:02:45 469.lan kernel: usb 1-4: new high-speed USB device number 6 using ehci-pci Jan 04 00:02:45 469.lan kernel: usb 1-4: New USB device found, idVendor=12d1, idProduct=1001 Jan 04 00:02:45 469.lan kernel: usb 1-4: New USB device strings: Mfr=3, Product=2, SerialNumber=0 Jan 04 00:02:45 469.lan kernel: usb 1-4: Product: HUAWEI Mobile Jan 04 00:02:45 469.lan kernel: usb 1-4: Manufacturer: HUAWEI Technology Jan 04 00:02:45 469.lan kernel: usb-storage 1-4:1.0: USB Mass Storage device detected Jan 04 00:02:45 469.lan kernel: usb-storage 1-4:1.1: USB Mass Storage device detected Jan 04 00:02:45 469.lan kernel: usb-storage 1-4:1.2: USB Mass Storage device detected Jan 04 00:02:45 469.lan kernel: usb-storage 1-4:1.3: USB Mass Storage device detected Jan 04 00:02:45 469.lan kernel: scsi host38: usb-storage 1-4:1.3 Jan 04 00:02:45 469.lan kernel: usb-storage 1-4:1.4: USB Mass Storage device detected Jan 04 00:02:45 469.lan kernel: scsi host39: usb-storage 1-4:1.4 Jan 04 00:02:45 469.lan root[23474]: usb_modeswitch: switched to 12d1:1001 on 001/006 Jan 04 00:02:46 469.lan kernel: scsi 38:0:0:0: CD-ROM HUAWEI Mass Storage 2.31 PQ: 0 ANSI: 2 Jan 04 00:02:46 469.lan kernel: scsi 39:0:0:0: Direct-Access HUAWEI SD Storage 2.31 PQ: 0 ANSI: 2 Jan 04 00:02:46 469.lan kernel: sr 38:0:0:0: [sr1] scsi-1 drive Jan 04 00:02:46 469.lan kernel: sr 38:0:0:0: Attached scsi CD-ROM sr1 Jan 04 00:02:46 469.lan kernel: sr 38:0:0:0: Attached scsi generic sg3 type 5 Jan 04 00:02:46 469.lan kernel: sd 39:0:0:0: Attached scsi generic sg4 type 0 Jan 04 00:02:46 469.lan kernel: sd 39:0:0:0: [sdc] Attached SCSI removable disk Jan 04 00:02:46 469.lan kernel: usbcore: registered new interface driver option Jan 04 00:02:46 469.lan kernel: usbserial: USB Serial support registered for GSM modem (1-port) Jan 04 00:02:46 469.lan kernel: option 1-4:1.0: GSM modem (1-port) converter detected Jan 04 00:02:46 469.lan kernel: usb 1-4: GSM modem (1-port) converter now attached to ttyUSB0 Jan 04 00:02:46 469.lan kernel: option 1-4:1.1: GSM modem (1-port) converter detected Jan 04 00:02:46 469.lan kernel: usb 1-4: GSM modem (1-port) converter now attached to ttyUSB1 Jan 04 00:02:46 469.lan kernel: option 1-4:1.2: GSM modem (1-port) converter detected Jan 04 00:02:46 469.lan kernel: usb 1-4: GSM modem (1-port) converter now attached to ttyUSB2 Jan 04 00:02:46 469.lan root[23479]: usb_modeswitch: add device ID 12d1:1001 to driver "option" Jan 04 00:02:46 469.lan root[23480]: usb_modeswitch: please report the device ID to the Linux USB developers! Jan 04 00:02:46 469.lan mtp-probe[23492]: checking bus 1, device 6: "/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4" Jan 04 00:02:46 469.lan mtp-probe[23492]: bus: 1, device: 6 was not an MTP device Jan 04 00:02:47 469.lan ModemManager[1393]: <warn> (ttyUSB1): port attributes not fully set Jan 04 00:02:47 469.lan ModemManager[1393]: <warn> (ttyUSB2): port attributes not fully set Jan 04 00:02:47 469.lan ModemManager[1393]: <warn> (ttyUSB0): port attributes not fully set Jan 04 00:02:56 469.lan ModemManager[1393]: <warn> (ttyUSB2): port attributes not fully set Jan 04 00:02:57 469.lan ModemManager[1393]: <warn> (ttyUSB0): port attributes not fully set Jan 04 00:02:57 469.lan kernel: sd 39:0:0:0: [sdc] 3854336 512-byte logical blocks: (1.97 GB/1.83 GiB) Jan 04 00:02:57 469.lan kernel: sd 39:0:0:0: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA Jan 04 00:02:57 469.lan kernel: sdc: sdc1 sdc2 Jan 04 00:03:00 469.lan ModemManager[1393]: <info> Creating modem with plugin 'Generic' and '3' ports Jan 04 00:03:00 469.lan ModemManager[1393]: <warn> (ttyUSB0): port attributes not fully set Jan 04 00:03:00 469.lan ModemManager[1393]: <info> Modem for device at '/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4' successfully created Jan 04 00:03:01 469.lan ModemManager[1393]: <info> Modem: state changed (unknown -> disabled) Jan 04 00:03:01 469.lan NetworkManager[1596]: <info> (ttyUSB0): modem state changed, 'disabled' --> 'enabling' (reason: user preference) Jan 04 00:03:01 469.lan NetworkManager[1596]: <info> (ttyUSB0): new Broadband device (carrier: UNKNOWN, driver: 'option1', ifindex: 0) Jan 04 00:03:01 469.lan NetworkManager[1596]: <info> (ttyUSB0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2] Jan 04 00:03:01 469.lan NetworkManager[1596]: <info> (ttyUSB0): modem state 'enabling' Jan 04 00:03:01 469.lan NetworkManager[1596]: <info> (ttyUSB0): device state change: unavailable -> disconnected (reason 'none') [20 30 0] Jan 04 00:03:01 469.lan ModemManager[1393]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: state changed (disabled -> enabling) Jan 04 00:03:01 469.lan ModemManager[1393]: <warn> (ttyUSB0): port attributes not fully set Jan 04 00:03:01 469.lan ModemManager[1393]: <warn> (ttyUSB2): port attributes not fully set Jan 04 00:03:01 469.lan ModemManager[1393]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (unknown -> registering) Jan 04 00:03:01 469.lan ModemManager[1393]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (registering -> home) Jan 04 00:03:02 469.lan ModemManager[1393]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: state changed (enabling -> registered) Jan 04 00:03:02 469.lan NetworkManager[1596]: <info> (ttyUSB0): modem state changed, 'enabling' --> 'registered' (reason: user-requested) Jan 04 00:03:26 469.lan NetworkManager[1596]: <info> (ttyUSB0): Activation: starting connection 'O2 Internet' (4fc980c2-41ca-409b-9e08-f294058d7e79) Jan 04 00:03:26 469.lan NetworkManager[1596]: <info> (ttyUSB0): device state change: disconnected -> prepare (reason 'none') [30 40 0] Jan 04 00:03:26 469.lan NetworkManager[1596]: <info> NetworkManager state is now CONNECTING Jan 04 00:03:26 469.lan ModemManager[1393]: <info> Simple connect started... Jan 04 00:03:26 469.lan ModemManager[1393]: <info> Simple connect state (4/8): Wait to get fully enabled Jan 04 00:03:26 469.lan ModemManager[1393]: <info> Simple connect state (5/8): Register Jan 04 00:03:26 469.lan ModemManager[1393]: <info> Simple connect state (6/8): Bearer Jan 04 00:03:26 469.lan ModemManager[1393]: <info> Simple connect state (7/8): Connect Jan 04 00:03:26 469.lan ModemManager[1393]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: state changed (registered -> connecting) Jan 04 00:03:26 469.lan NetworkManager[1596]: <info> (ttyUSB0): modem state changed, 'registered' --> 'connecting' (reason: user-requested) Jan 04 00:03:26 469.lan ModemManager[1393]: <info> Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connecting -> connected) Jan 04 00:03:26 469.lan ModemManager[1393]: <info> Simple connect state (8/8): All done Jan 04 00:03:26 469.lan NetworkManager[1596]: <info> (ttyUSB0): modem state changed, 'connecting' --> 'connected' (reason: user-requested) Jan 04 00:03:26 469.lan NetworkManager[1596]: <warn> (ttyUSB0): failed to look up interface index Jan 04 00:03:26 469.lan NetworkManager[1596]: <info> (ttyUSB0): device state change: prepare -> config (reason 'none') [40 50 0] Jan 04 00:03:26 469.lan audit: NETFILTER_CFG table=mangle family=2 entries=39 Jan 04 00:03:26 469.lan audit[23552]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=55c220b48420 items=0 ppid=1396 pid=23552 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:03:26 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4900505245524F5554494E475F5A4F4E45530031002D74006D616E676C65002D690074747955534230002D67005052455F7075626C6963 Jan 04 00:03:26 469.lan audit: NETFILTER_CFG table=mangle family=10 entries=39 Jan 04 00:03:26 469.lan audit[23553]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=55d806be4fd0 items=0 ppid=1396 pid=23553 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:03:26 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4900505245524F5554494E475F5A4F4E45530031002D74006D616E676C65002D690074747955534230002D67005052455F7075626C6963 Jan 04 00:03:26 469.lan audit: NETFILTER_CFG table=nat family=2 entries=50 Jan 04 00:03:26 469.lan audit[23554]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=5612d4fd1030 items=0 ppid=1396 pid=23554 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:03:26 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4900504F5354524F5554494E475F5A4F4E45530031002D74006E6174002D6F0074747955534230002D6700504F53545F7075626C6963 Jan 04 00:03:26 469.lan audit: NETFILTER_CFG table=nat family=10 entries=50 Jan 04 00:03:26 469.lan audit[23555]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=564d14b88f50 items=0 ppid=1396 pid=23555 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:03:26 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4900504F5354524F5554494E475F5A4F4E45530031002D74006E6174002D6F0074747955534230002D6700504F53545F7075626C6963 Jan 04 00:03:26 469.lan audit: NETFILTER_CFG table=nat family=2 entries=51 Jan 04 00:03:26 469.lan audit[23556]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=55fb423a61b0 items=0 ppid=1396 pid=23556 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:03:26 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4900505245524F5554494E475F5A4F4E45530031002D74006E6174002D690074747955534230002D67005052455F7075626C6963 Jan 04 00:03:26 469.lan audit: NETFILTER_CFG table=nat family=10 entries=51 Jan 04 00:03:26 469.lan audit[23557]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=55d0e70a7140 items=0 ppid=1396 pid=23557 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:03:26 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4900505245524F5554494E475F5A4F4E45530031002D74006E6174002D690074747955534230002D67005052455F7075626C6963 Jan 04 00:03:26 469.lan audit: NETFILTER_CFG table=filter family=2 entries=82 Jan 04 00:03:26 469.lan audit[23558]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=5593b99da930 items=0 ppid=1396 pid=23558 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:03:26 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4900464F52574152445F494E5F5A4F4E45530031002D740066696C746572002D690074747955534230002D6700465744495F7075626C6963 Jan 04 00:03:26 469.lan audit: NETFILTER_CFG table=filter family=10 entries=83 Jan 04 00:03:26 469.lan audit[23559]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=564787a717d0 items=0 ppid=1396 pid=23559 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:03:26 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4900464F52574152445F494E5F5A4F4E45530031002D740066696C746572002D690074747955534230002D6700465744495F7075626C6963 Jan 04 00:03:26 469.lan audit: NETFILTER_CFG table=filter family=2 entries=83 Jan 04 00:03:26 469.lan audit[23560]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=5604b906eaa0 items=0 ppid=1396 pid=23560 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:03:26 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4900494E5055545F5A4F4E45530031002D740066696C746572002D690074747955534230002D6700494E5F7075626C6963 Jan 04 00:03:26 469.lan audit: NETFILTER_CFG table=filter family=10 entries=84 Jan 04 00:03:26 469.lan audit[23561]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=56465ebaf9c0 items=0 ppid=1396 pid=23561 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:03:26 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4900494E5055545F5A4F4E45530031002D740066696C746572002D690074747955534230002D6700494E5F7075626C6963 Jan 04 00:03:26 469.lan audit: NETFILTER_CFG table=filter family=2 entries=84 Jan 04 00:03:26 469.lan audit[23562]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=5617fc11dc20 items=0 ppid=1396 pid=23562 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:03:26 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4900464F52574152445F4F55545F5A4F4E45530031002D740066696C746572002D6F0074747955534230002D67004657444F5F7075626C6963 Jan 04 00:03:26 469.lan audit: NETFILTER_CFG table=filter family=10 entries=85 Jan 04 00:03:26 469.lan audit[23563]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=563d6c6bdbb0 items=0 ppid=1396 pid=23563 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:03:26 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4900464F52574152445F4F55545F5A4F4E45530031002D740066696C746572002D6F0074747955534230002D67004657444F5F7075626C6963 Jan 04 00:03:27 469.lan NetworkManager[1596]: <info> (ttyUSB0): device state change: config -> ip-config (reason 'none') [50 70 0] Jan 04 00:03:27 469.lan NetworkManager[1596]: <warn> (ttyUSB0): interface ttyUSB0 not up for IP configuration Jan 04 00:03:27 469.lan NetworkManager[1596]: <info> (ttyUSB0): using modem-specified IP timeout: 20 seconds Jan 04 00:03:27 469.lan NetworkManager[1596]: <info> starting PPP connection Jan 04 00:03:27 469.lan NetworkManager[1596]: <info> pppd started with pid 23564 Jan 04 00:03:27 469.lan NetworkManager[1596]: <info> (ttyUSB0): IPv6 configuration disabled Jan 04 00:03:27 469.lan pppd[23564]: Plugin /usr/lib64/pppd/2.4.7/nm-pppd-plugin.so loaded. Jan 04 00:03:27 469.lan kernel: PPP generic driver version 2.4.2 Jan 04 00:03:27 469.lan pppd[23564]: pppd 2.4.7 started by root, uid 0 Jan 04 00:03:27 469.lan NetworkManager[1596]: Plugin /usr/lib64/pppd/2.4.7/nm-pppd-plugin.so loaded. Jan 04 00:03:27 469.lan NetworkManager[1596]: nm-pppd-plugin-Message: nm-ppp-plugin: (plugin_init): initializing Jan 04 00:03:27 469.lan NetworkManager[1596]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_phasechange): status 3 / phase 'serial connection' Jan 04 00:03:27 469.lan NetworkManager[1596]: Using interface ppp0 Jan 04 00:03:27 469.lan NetworkManager[1596]: Connect: ppp0 <--> /dev/ttyUSB0 Jan 04 00:03:27 469.lan NetworkManager[1596]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_phasechange): status 5 / phase 'establish' Jan 04 00:03:27 469.lan NetworkManager[1596]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_phasechange): status 6 / phase 'authenticate' Jan 04 00:03:27 469.lan NetworkManager[1596]: nm-pppd-plugin-Message: nm-ppp-plugin: (get_credentials): passwd-hook, requesting credentials... Jan 04 00:03:27 469.lan pppd[23564]: Using interface ppp0 Jan 04 00:03:27 469.lan pppd[23564]: Connect: ppp0 <--> /dev/ttyUSB0 Jan 04 00:03:27 469.lan NetworkManager[1596]: <info> (ppp0): new Generic device (carrier: UNKNOWN, driver: 'unknown', ifindex: 5) Jan 04 00:03:27 469.lan NetworkManager[1596]: nm-pppd-plugin-Message: nm-ppp-plugin: (get_credentials): got credentials from NetworkManager Jan 04 00:03:27 469.lan pppd[23564]: CHAP authentication succeeded Jan 04 00:03:27 469.lan pppd[23564]: CHAP authentication succeeded Jan 04 00:03:27 469.lan NetworkManager[1596]: CHAP authentication succeeded Jan 04 00:03:27 469.lan NetworkManager[1596]: CHAP authentication succeeded Jan 04 00:03:27 469.lan NetworkManager[1596]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_phasechange): status 8 / phase 'network' Jan 04 00:03:27 469.lan kernel: PPP BSD Compression module registered Jan 04 00:03:27 469.lan kernel: PPP Deflate Compression module registered Jan 04 00:03:29 469.lan pppd[23564]: Could not determine remote IP address: defaulting to 10.64.64.64 Jan 04 00:03:29 469.lan NetworkManager[1596]: Could not determine remote IP address: defaulting to 10.64.64.64 Jan 04 00:03:29 469.lan pppd[23564]: local IP address 100.121.49.58 Jan 04 00:03:29 469.lan pppd[23564]: remote IP address 10.64.64.64 Jan 04 00:03:29 469.lan pppd[23564]: primary DNS address 160.218.161.60 Jan 04 00:03:29 469.lan pppd[23564]: secondary DNS address 160.218.167.5 Jan 04 00:03:29 469.lan NetworkManager[1596]: local IP address 100.121.49.58 Jan 04 00:03:29 469.lan NetworkManager[1596]: remote IP address 10.64.64.64 Jan 04 00:03:29 469.lan NetworkManager[1596]: primary DNS address 160.218.161.60 Jan 04 00:03:29 469.lan NetworkManager[1596]: secondary DNS address 160.218.167.5 Jan 04 00:03:29 469.lan NetworkManager[1596]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_phasechange): status 9 / phase 'running' Jan 04 00:03:29 469.lan NetworkManager[1596]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_ip_up): ip-up event Jan 04 00:03:29 469.lan NetworkManager[1596]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_ip_up): sending IPv4 config to NetworkManager... Jan 04 00:03:29 469.lan NetworkManager[1596]: <info> keyfile: add connection in-memory (952cd8b0-2394-46d3-9f58-690cb722feaa,"ppp0") Jan 04 00:03:29 469.lan NetworkManager[1596]: <info> (ppp0): device state change: unmanaged -> unavailable (reason 'connection-assumed') [10 20 41] Jan 04 00:03:29 469.lan NetworkManager[1596]: <info> (ppp0): device state change: unavailable -> disconnected (reason 'connection-assumed') [20 30 41] Jan 04 00:03:29 469.lan NetworkManager[1596]: <info> (ppp0): Activation: starting connection 'ppp0' (952cd8b0-2394-46d3-9f58-690cb722feaa) Jan 04 00:03:29 469.lan systemd[1]: Starting Network Manager Script Dispatcher Service... Jan 04 00:03:29 469.lan NetworkManager[1596]: <info> PPP manager (IPv4 Config Get) reply received. Jan 04 00:03:29 469.lan NetworkManager[1596]: <info> (ppp0): device state change: disconnected -> prepare (reason 'none') [30 40 0] Jan 04 00:03:29 469.lan NetworkManager[1596]: <info> (ttyUSB0): device state change: ip-config -> ip-check (reason 'none') [70 80 0] Jan 04 00:03:29 469.lan dbus[1402]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' Jan 04 00:03:29 469.lan NetworkManager[1596]: <info> (ppp0): device state change: prepare -> config (reason 'none') [40 50 0] Jan 04 00:03:29 469.lan NetworkManager[1596]: <info> (ppp0): device state change: config -> ip-config (reason 'none') [50 70 0] Jan 04 00:03:29 469.lan dbus[1402]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher' Jan 04 00:03:29 469.lan systemd[1]: Started Network Manager Script Dispatcher Service. Jan 04 00:03:29 469.lan audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success' Jan 04 00:03:29 469.lan nm-dispatcher[23604]: Dispatching action 'pre-up' for ppp0 Jan 04 00:03:29 469.lan NetworkManager[1596]: <info> (ppp0): device state change: ip-config -> ip-check (reason 'none') [70 80 0] Jan 04 00:03:29 469.lan NetworkManager[1596]: <info> (ttyUSB0): device state change: ip-check -> secondaries (reason 'none') [80 90 0] Jan 04 00:03:29 469.lan nm-dispatcher[23604]: Dispatching action 'pre-up' for ppp0 Jan 04 00:03:29 469.lan NetworkManager[1596]: <info> (ttyUSB0): device state change: secondaries -> activated (reason 'none') [90 100 0] Jan 04 00:03:29 469.lan NetworkManager[1596]: <info> NetworkManager state is now CONNECTED_LOCAL Jan 04 00:03:29 469.lan NetworkManager[1596]: <info> Policy set 'ppp0' (ppp0) as default for IPv4 routing and DNS. Jan 04 00:03:29 469.lan NetworkManager[1596]: <info> (ttyUSB0): Activation: successful, device activated. Jan 04 00:03:29 469.lan NetworkManager[1596]: <info> (ppp0): device state change: ip-check -> secondaries (reason 'none') [80 90 0] Jan 04 00:03:29 469.lan nm-dispatcher[23604]: Dispatching action 'up' for ppp0 Jan 04 00:03:29 469.lan systemd[1]: iscsi.service: Unit cannot be reloaded because it is inactive. Jan 04 00:03:29 469.lan nm-dispatcher[23604]: Redirecting to /bin/systemctl restart ntpd.service Jan 04 00:03:29 469.lan systemd[1]: Stopping Network Time Service... Jan 04 00:03:29 469.lan ntpd[14861]: ntpd exiting on signal 15 Jan 04 00:03:29 469.lan audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=ntpd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success' Jan 04 00:03:29 469.lan systemd[1]: Starting Network Time Service... Jan 04 00:03:29 469.lan ntpd[23651]: ntpd 4.2.6p5 Thu Oct 22 16:09:59 UTC 2015 (1) Jan 04 00:03:29 469.lan systemd[1]: Started Network Time Service. Jan 04 00:03:29 469.lan audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=ntpd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success' Jan 04 00:03:29 469.lan ntpd[23652]: proto: precision = 0.698 usec Jan 04 00:03:29 469.lan ntpd[23652]: 0.0.0.0 c01d 0d kern kernel time sync enabled Jan 04 00:03:29 469.lan ntpd[23652]: ntp_io: estimated max descriptors: 1024, initial socket boundary: 16 Jan 04 00:03:29 469.lan ntpd[23652]: Listen and drop on 0 v4wildcard 0.0.0.0 UDP 123 Jan 04 00:03:29 469.lan ntpd[23652]: Listen and drop on 1 v6wildcard :: UDP 123 Jan 04 00:03:29 469.lan ntpd[23652]: Listen normally on 2 lo 127.0.0.1 UDP 123 Jan 04 00:03:29 469.lan ntpd[23652]: Listen normally on 3 ppp0 100.121.49.58 UDP 123 Jan 04 00:03:29 469.lan ntpd[23652]: Listen normally on 4 lo ::1 UDP 123 Jan 04 00:03:29 469.lan ntpd[23652]: Listening on routing socket on fd #21 for interface updates Jan 04 00:03:30 469.lan ntpd[23652]: 0.0.0.0 c016 06 restart Jan 04 00:03:30 469.lan ntpd[23652]: 0.0.0.0 c012 02 freq_set kernel 6.003 PPM Jan 04 00:03:30 469.lan ntpd[23652]: 0.0.0.0 c615 05 clock_sync Jan 04 00:03:40 469.lan audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success' Jan 04 00:03:57 469.lan pppd[23564]: IPV6CP: timeout sending Config-Requests Jan 04 00:03:57 469.lan NetworkManager[1596]: IPV6CP: timeout sending Config-Requests And now the attempt after replugging the modem, where the connection fails: Jan 04 00:06:24 469.lan kernel: usb 2-1: new high-speed USB device number 41 using ehci-pci Jan 04 00:06:25 469.lan kernel: usb 2-1: New USB device found, idVendor=12d1, idProduct=1446 Jan 04 00:06:25 469.lan kernel: usb 2-1: New USB device strings: Mfr=3, Product=2, SerialNumber=0 Jan 04 00:06:25 469.lan kernel: usb 2-1: Product: HUAWEI Mobile Jan 04 00:06:25 469.lan kernel: usb 2-1: Manufacturer: HUAWEI Technology Jan 04 00:06:25 469.lan kernel: usb-storage 2-1:1.0: USB Mass Storage device detected Jan 04 00:06:25 469.lan kernel: scsi host47: usb-storage 2-1:1.0 Jan 04 00:06:25 469.lan kernel: usb-storage 2-1:1.1: USB Mass Storage device detected Jan 04 00:06:25 469.lan kernel: scsi host48: usb-storage 2-1:1.1 Jan 04 00:06:25 469.lan mtp-probe[24068]: checking bus 2, device 41: "/sys/devices/pci0000:00/0000:00:1d.7/usb2/2-1" Jan 04 00:06:25 469.lan mtp-probe[24068]: bus: 2, device: 41 was not an MTP device Jan 04 00:06:25 469.lan root[24090]: usb_modeswitch: use overriding config file /etc/usb_modeswitch.d/12d1:1446; make sure this is intended Jan 04 00:06:25 469.lan root[24091]: usb_modeswitch: please report any new or corrected settings; otherwise, check for outdated files Jan 04 00:06:25 469.lan usb_modeswitch[24093]: switch device 12d1:1446 on 002/041 Jan 04 00:06:25 469.lan kernel: usb 2-1: USB disconnect, device number 41 Jan 04 00:06:29 469.lan kernel: usb 2-1: new high-speed USB device number 42 using ehci-pci Jan 04 00:06:29 469.lan kernel: usb 2-1: New USB device found, idVendor=12d1, idProduct=1001 Jan 04 00:06:29 469.lan kernel: usb 2-1: New USB device strings: Mfr=3, Product=2, SerialNumber=0 Jan 04 00:06:29 469.lan kernel: usb 2-1: Product: HUAWEI Mobile Jan 04 00:06:29 469.lan kernel: usb 2-1: Manufacturer: HUAWEI Technology Jan 04 00:06:29 469.lan kernel: usb-storage 2-1:1.0: USB Mass Storage device detected Jan 04 00:06:29 469.lan kernel: option 2-1:1.0: GSM modem (1-port) converter detected Jan 04 00:06:29 469.lan kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB0 Jan 04 00:06:29 469.lan kernel: usb-storage 2-1:1.1: USB Mass Storage device detected Jan 04 00:06:29 469.lan kernel: option 2-1:1.1: GSM modem (1-port) converter detected Jan 04 00:06:29 469.lan kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB1 Jan 04 00:06:29 469.lan kernel: usb-storage 2-1:1.2: USB Mass Storage device detected Jan 04 00:06:29 469.lan kernel: option 2-1:1.2: GSM modem (1-port) converter detected Jan 04 00:06:29 469.lan kernel: usb 2-1: GSM modem (1-port) converter now attached to ttyUSB2 Jan 04 00:06:29 469.lan kernel: usb-storage 2-1:1.3: USB Mass Storage device detected Jan 04 00:06:29 469.lan kernel: scsi host52: usb-storage 2-1:1.3 Jan 04 00:06:29 469.lan kernel: usb-storage 2-1:1.4: USB Mass Storage device detected Jan 04 00:06:29 469.lan kernel: scsi host53: usb-storage 2-1:1.4 Jan 04 00:06:30 469.lan root[24115]: usb_modeswitch: switched to 12d1:1001 on 002/042 Jan 04 00:06:30 469.lan kernel: scsi 52:0:0:0: CD-ROM HUAWEI Mass Storage 2.31 PQ: 0 ANSI: 2 Jan 04 00:06:30 469.lan kernel: scsi 53:0:0:0: Direct-Access HUAWEI SD Storage 2.31 PQ: 0 ANSI: 2 Jan 04 00:06:30 469.lan kernel: sr 52:0:0:0: [sr1] scsi-1 drive Jan 04 00:06:30 469.lan kernel: sr 52:0:0:0: Attached scsi CD-ROM sr1 Jan 04 00:06:30 469.lan kernel: sr 52:0:0:0: Attached scsi generic sg3 type 5 Jan 04 00:06:30 469.lan kernel: sd 53:0:0:0: Attached scsi generic sg4 type 0 Jan 04 00:06:30 469.lan kernel: sd 53:0:0:0: [sdc] Attached SCSI removable disk Jan 04 00:06:32 469.lan mtp-probe[24127]: checking bus 2, device 42: "/sys/devices/pci0000:00/0000:00:1d.7/usb2/2-1" Jan 04 00:06:32 469.lan mtp-probe[24127]: bus: 2, device: 42 was not an MTP device Jan 04 00:06:32 469.lan ModemManager[1393]: <warn> (ttyUSB1): port attributes not fully set Jan 04 00:06:32 469.lan ModemManager[1393]: <warn> (ttyUSB2): port attributes not fully set Jan 04 00:06:41 469.lan ModemManager[1393]: <warn> (ttyUSB2): port attributes not fully set Jan 04 00:06:42 469.lan kernel: sd 53:0:0:0: [sdc] 3854336 512-byte logical blocks: (1.97 GB/1.83 GiB) Jan 04 00:06:42 469.lan kernel: sd 53:0:0:0: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA Jan 04 00:06:42 469.lan kernel: sdc: sdc1 sdc2 Jan 04 00:06:44 469.lan ModemManager[1393]: <info> Creating modem with plugin 'Generic' and '3' ports Jan 04 00:06:44 469.lan ModemManager[1393]: <warn> Could not grab port (tty/ttyUSB0): 'Cannot add port 'tty/ttyUSB0', unhandled serial type' Jan 04 00:06:44 469.lan ModemManager[1393]: <warn> (ttyUSB2): port attributes not fully set Jan 04 00:06:44 469.lan ModemManager[1393]: <info> Modem for device at '/sys/devices/pci0000:00/0000:00:1d.7/usb2/2-1' successfully created Jan 04 00:06:44 469.lan ModemManager[1393]: <info> Modem: state changed (unknown -> disabled) Jan 04 00:06:44 469.lan NetworkManager[1596]: <info> (ttyUSB2): modem state changed, 'disabled' --> 'enabling' (reason: user preference) Jan 04 00:06:44 469.lan NetworkManager[1596]: <info> (ttyUSB2): new Broadband device (carrier: UNKNOWN, driver: 'option1', ifindex: 0) Jan 04 00:06:44 469.lan NetworkManager[1596]: <info> (ttyUSB2): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2] Jan 04 00:06:44 469.lan NetworkManager[1596]: <info> (ttyUSB2): modem state 'enabling' Jan 04 00:06:44 469.lan NetworkManager[1596]: <info> (ttyUSB2): device state change: unavailable -> disconnected (reason 'none') [20 30 0] Jan 04 00:06:44 469.lan ModemManager[1393]: <info> Modem /org/freedesktop/ModemManager1/Modem/2: state changed (disabled -> enabling) Jan 04 00:06:44 469.lan ModemManager[1393]: <warn> (ttyUSB2): port attributes not fully set Jan 04 00:06:45 469.lan ModemManager[1393]: <info> Modem /org/freedesktop/ModemManager1/Modem/2: 3GPP Registration state changed (unknown -> registering) Jan 04 00:06:45 469.lan ModemManager[1393]: <info> Modem /org/freedesktop/ModemManager1/Modem/2: 3GPP Registration state changed (registering -> home) Jan 04 00:06:45 469.lan ModemManager[1393]: <info> Modem /org/freedesktop/ModemManager1/Modem/2: state changed (enabling -> registered) Jan 04 00:06:45 469.lan NetworkManager[1596]: <info> (ttyUSB2): modem state changed, 'enabling' --> 'registered' (reason: user-requested) Jan 04 00:06:57 469.lan NetworkManager[1596]: <info> (ttyUSB2): Activation: starting connection 'O2 Internet' (4fc980c2-41ca-409b-9e08-f294058d7e79) Jan 04 00:06:57 469.lan NetworkManager[1596]: <info> (ttyUSB2): device state change: disconnected -> prepare (reason 'none') [30 40 0] Jan 04 00:06:57 469.lan NetworkManager[1596]: <info> NetworkManager state is now CONNECTING Jan 04 00:06:57 469.lan ModemManager[1393]: <info> Simple connect started... Jan 04 00:06:57 469.lan ModemManager[1393]: <info> Simple connect state (4/8): Wait to get fully enabled Jan 04 00:06:57 469.lan ModemManager[1393]: <info> Simple connect state (5/8): Register Jan 04 00:06:57 469.lan ModemManager[1393]: <info> Simple connect state (6/8): Bearer Jan 04 00:06:57 469.lan ModemManager[1393]: <info> Simple connect state (7/8): Connect Jan 04 00:06:57 469.lan ModemManager[1393]: <info> Modem /org/freedesktop/ModemManager1/Modem/2: state changed (registered -> connecting) Jan 04 00:06:57 469.lan NetworkManager[1596]: <info> (ttyUSB2): modem state changed, 'registered' --> 'connecting' (reason: user-requested) Jan 04 00:06:57 469.lan ModemManager[1393]: <info> Modem /org/freedesktop/ModemManager1/Modem/2: state changed (connecting -> connected) Jan 04 00:06:57 469.lan ModemManager[1393]: <info> Simple connect state (8/8): All done Jan 04 00:06:57 469.lan NetworkManager[1596]: <info> (ttyUSB2): modem state changed, 'connecting' --> 'connected' (reason: user-requested) Jan 04 00:06:57 469.lan NetworkManager[1596]: <warn> (ttyUSB2): failed to look up interface index Jan 04 00:06:57 469.lan NetworkManager[1596]: <info> (ttyUSB2): device state change: prepare -> config (reason 'none') [40 50 0] Jan 04 00:06:57 469.lan audit: NETFILTER_CFG table=mangle family=2 entries=40 Jan 04 00:06:57 469.lan audit[24182]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=557d8b34d590 items=0 ppid=1396 pid=24182 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:06:57 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4900505245524F5554494E475F5A4F4E45530031002D74006D616E676C65002D690074747955534232002D67005052455F7075626C6963 Jan 04 00:06:57 469.lan audit: NETFILTER_CFG table=mangle family=10 entries=40 Jan 04 00:06:57 469.lan audit[24183]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=55cb1d9b11c0 items=0 ppid=1396 pid=24183 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:06:57 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4900505245524F5554494E475F5A4F4E45530031002D74006D616E676C65002D690074747955534232002D67005052455F7075626C6963 Jan 04 00:06:57 469.lan audit: NETFILTER_CFG table=nat family=2 entries=52 Jan 04 00:06:57 469.lan audit[24184]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=55e4747fc320 items=0 ppid=1396 pid=24184 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:06:57 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4900504F5354524F5554494E475F5A4F4E45530031002D74006E6174002D6F0074747955534232002D6700504F53545F7075626C6963 Jan 04 00:06:57 469.lan audit: NETFILTER_CFG table=nat family=10 entries=52 Jan 04 00:06:57 469.lan audit[24185]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=55f20a584330 items=0 ppid=1396 pid=24185 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:06:57 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4900504F5354524F5554494E475F5A4F4E45530031002D74006E6174002D6F0074747955534232002D6700504F53545F7075626C6963 Jan 04 00:06:57 469.lan audit: NETFILTER_CFG table=nat family=2 entries=53 Jan 04 00:06:57 469.lan audit[24186]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=5622f84bc4a0 items=0 ppid=1396 pid=24186 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:06:57 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4900505245524F5554494E475F5A4F4E45530031002D74006E6174002D690074747955534232002D67005052455F7075626C6963 Jan 04 00:06:57 469.lan audit: NETFILTER_CFG table=nat family=10 entries=53 Jan 04 00:06:57 469.lan audit[24187]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=55b40787a520 items=0 ppid=1396 pid=24187 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:06:57 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4900505245524F5554494E475F5A4F4E45530031002D74006E6174002D690074747955534232002D67005052455F7075626C6963 Jan 04 00:06:57 469.lan audit: NETFILTER_CFG table=filter family=2 entries=85 Jan 04 00:06:57 469.lan audit[24188]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=556693232d90 items=0 ppid=1396 pid=24188 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:06:57 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4900464F52574152445F494E5F5A4F4E45530031002D740066696C746572002D690074747955534232002D6700465744495F7075626C6963 Jan 04 00:06:57 469.lan audit: NETFILTER_CFG table=filter family=10 entries=86 Jan 04 00:06:57 469.lan audit[24189]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=55d7360f8da0 items=0 ppid=1396 pid=24189 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:06:57 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4900464F52574152445F494E5F5A4F4E45530031002D740066696C746572002D690074747955534232002D6700465744495F7075626C6963 Jan 04 00:06:57 469.lan audit: NETFILTER_CFG table=filter family=2 entries=86 Jan 04 00:06:57 469.lan audit[24190]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=55d3b0357f10 items=0 ppid=1396 pid=24190 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:06:57 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4900494E5055545F5A4F4E45530031002D740066696C746572002D690074747955534232002D6700494E5F7075626C6963 Jan 04 00:06:57 469.lan audit: NETFILTER_CFG table=filter family=10 entries=87 Jan 04 00:06:57 469.lan audit[24191]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=55ac88d0ef90 items=0 ppid=1396 pid=24191 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:06:57 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4900494E5055545F5A4F4E45530031002D740066696C746572002D690074747955534232002D6700494E5F7075626C6963 Jan 04 00:06:57 469.lan audit: NETFILTER_CFG table=filter family=2 entries=87 Jan 04 00:06:57 469.lan audit[24192]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=556d5d467080 items=0 ppid=1396 pid=24192 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:06:57 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4900464F52574152445F4F55545F5A4F4E45530031002D740066696C746572002D6F0074747955534232002D67004657444F5F7075626C6963 Jan 04 00:06:57 469.lan audit: NETFILTER_CFG table=filter family=10 entries=88 Jan 04 00:06:57 469.lan audit[24193]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=5640e620b180 items=0 ppid=1396 pid=24193 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:06:57 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4900464F52574152445F4F55545F5A4F4E45530031002D740066696C746572002D6F0074747955534232002D67004657444F5F7075626C6963 Jan 04 00:06:57 469.lan NetworkManager[1596]: <info> (ttyUSB2): device state change: config -> ip-config (reason 'none') [50 70 0] Jan 04 00:06:57 469.lan NetworkManager[1596]: <warn> (ttyUSB2): interface ttyUSB2 not up for IP configuration Jan 04 00:06:57 469.lan NetworkManager[1596]: <info> (ttyUSB2): using modem-specified IP timeout: 20 seconds Jan 04 00:06:57 469.lan NetworkManager[1596]: <info> starting PPP connection Jan 04 00:06:57 469.lan NetworkManager[1596]: <info> pppd started with pid 24194 Jan 04 00:06:57 469.lan NetworkManager[1596]: <info> (ttyUSB2): IPv6 configuration disabled Jan 04 00:06:57 469.lan pppd[24194]: Plugin /usr/lib64/pppd/2.4.7/nm-pppd-plugin.so loaded. Jan 04 00:06:57 469.lan NetworkManager[1596]: Plugin /usr/lib64/pppd/2.4.7/nm-pppd-plugin.so loaded. Jan 04 00:06:57 469.lan NetworkManager[1596]: nm-pppd-plugin-Message: nm-ppp-plugin: (plugin_init): initializing Jan 04 00:06:57 469.lan pppd[24194]: pppd 2.4.7 started by root, uid 0 Jan 04 00:06:57 469.lan pppd[24194]: Removed stale lock on ttyUSB2 (pid 24021) Jan 04 00:06:57 469.lan NetworkManager[1596]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_phasechange): status 3 / phase 'serial connection' Jan 04 00:06:57 469.lan NetworkManager[1596]: Removed stale lock on ttyUSB2 (pid 24021) Jan 04 00:06:57 469.lan pppd[24194]: Using interface ppp0 Jan 04 00:06:57 469.lan pppd[24194]: Connect: ppp0 <--> /dev/ttyUSB2 Jan 04 00:06:57 469.lan NetworkManager[1596]: <info> (ppp0): new Generic device (carrier: UNKNOWN, driver: 'unknown', ifindex: 8) Jan 04 00:06:57 469.lan NetworkManager[1596]: Using interface ppp0 Jan 04 00:06:57 469.lan NetworkManager[1596]: Connect: ppp0 <--> /dev/ttyUSB2 Jan 04 00:06:57 469.lan NetworkManager[1596]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_phasechange): status 5 / phase 'establish' Jan 04 00:07:18 469.lan NetworkManager[1596]: <warn> pppd timed out or didn't initialize our dbus module Jan 04 00:07:18 469.lan pppd[24194]: Terminating on signal 15 Jan 04 00:07:18 469.lan NetworkManager[1596]: <info> (ttyUSB2): device state change: ip-config -> failed (reason 'ip-config-unavailable') [70 120 5] Jan 04 00:07:18 469.lan NetworkManager[1596]: <info> NetworkManager state is now DISCONNECTED Jan 04 00:07:18 469.lan NetworkManager[1596]: Terminating on signal 15 Jan 04 00:07:18 469.lan NetworkManager[1596]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_phasechange): status 10 / phase 'terminate' Jan 04 00:07:18 469.lan NetworkManager[1596]: <warn> (ttyUSB2): Activation: failed for connection 'O2 Internet' Jan 04 00:07:18 469.lan NetworkManager[1596]: <info> (ttyUSB2): device state change: failed -> disconnected (reason 'none') [120 30 0] Jan 04 00:07:18 469.lan ModemManager[1393]: <info> Modem /org/freedesktop/ModemManager1/Modem/2: state changed (connected -> disconnecting) Jan 04 00:07:18 469.lan dbus[1402]: [system] Rejected send message, 9 matched rules; type="error", sender=":1.10" (uid=0 pid=1596 comm="/usr/sbin/NetworkManager --no-daemon ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.160" (uid=0 pid=24194 comm="/usr/sbin/pppd nodetach lock nodefaultroute ipv6 ,") Jan 04 00:07:18 469.lan NetworkManager[1596]: <info> (ttyUSB2): modem state changed, 'connected' --> 'disconnecting' (reason: user-requested) Jan 04 00:07:18 469.lan audit: NETFILTER_CFG table=mangle family=2 entries=41 Jan 04 00:07:18 469.lan audit[24203]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=5615fdc4c560 items=0 ppid=1396 pid=24203 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:07:18 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4400505245524F5554494E475F5A4F4E4553002D74006D616E676C65002D690074747955534232002D67005052455F7075626C6963 Jan 04 00:07:18 469.lan audit: NETFILTER_CFG table=mangle family=10 entries=41 Jan 04 00:07:18 469.lan audit[24204]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=5642975b8180 items=0 ppid=1396 pid=24204 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:07:18 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4400505245524F5554494E475F5A4F4E4553002D74006D616E676C65002D690074747955534232002D67005052455F7075626C6963 Jan 04 00:07:18 469.lan audit: NETFILTER_CFG table=nat family=2 entries=54 Jan 04 00:07:18 469.lan audit[24205]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=55f414bca460 items=0 ppid=1396 pid=24205 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:07:18 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4400504F5354524F5554494E475F5A4F4E4553002D74006E6174002D6F0074747955534232002D6700504F53545F7075626C6963 Jan 04 00:07:18 469.lan audit: NETFILTER_CFG table=nat family=10 entries=54 Jan 04 00:07:18 469.lan audit[24206]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=55ff235854e0 items=0 ppid=1396 pid=24206 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:07:18 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4400504F5354524F5554494E475F5A4F4E4553002D74006E6174002D6F0074747955534232002D6700504F53545F7075626C6963 Jan 04 00:07:18 469.lan audit: NETFILTER_CFG table=nat family=2 entries=53 Jan 04 00:07:18 469.lan audit[24207]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=55d5bc19b2f0 items=0 ppid=1396 pid=24207 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:07:18 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4400505245524F5554494E475F5A4F4E4553002D74006E6174002D690074747955534232002D67005052455F7075626C6963 Jan 04 00:07:18 469.lan audit: NETFILTER_CFG table=nat family=10 entries=53 Jan 04 00:07:18 469.lan audit[24208]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=556ab4dc72f0 items=0 ppid=1396 pid=24208 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:07:18 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4400505245524F5554494E475F5A4F4E4553002D74006E6174002D690074747955534232002D67005052455F7075626C6963 Jan 04 00:07:18 469.lan audit: NETFILTER_CFG table=filter family=2 entries=88 Jan 04 00:07:18 469.lan audit[24209]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=555abfd4c050 items=0 ppid=1396 pid=24209 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:07:18 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4400464F52574152445F494E5F5A4F4E4553002D740066696C746572002D690074747955534232002D6700465744495F7075626C6963 Jan 04 00:07:18 469.lan audit: NETFILTER_CFG table=filter family=10 entries=89 Jan 04 00:07:18 469.lan audit[24210]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=5646f1177140 items=0 ppid=1396 pid=24210 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:07:18 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4400464F52574152445F494E5F5A4F4E4553002D740066696C746572002D690074747955534232002D6700465744495F7075626C6963 Jan 04 00:07:18 469.lan audit: NETFILTER_CFG table=filter family=2 entries=87 Jan 04 00:07:18 469.lan audit[24211]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=5568b7486ed0 items=0 ppid=1396 pid=24211 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:07:18 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4400494E5055545F5A4F4E4553002D740066696C746572002D690074747955534232002D6700494E5F7075626C6963 Jan 04 00:07:18 469.lan audit: NETFILTER_CFG table=filter family=10 entries=88 Jan 04 00:07:18 469.lan audit[24212]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=559338642f50 items=0 ppid=1396 pid=24212 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:07:18 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4400494E5055545F5A4F4E4553002D740066696C746572002D690074747955534232002D6700494E5F7075626C6963 Jan 04 00:07:18 469.lan audit: NETFILTER_CFG table=filter family=2 entries=86 Jan 04 00:07:18 469.lan audit[24213]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=55c344e20d60 items=0 ppid=1396 pid=24213 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:07:18 469.lan audit: PROCTITLE proctitle=2F7362696E2F69707461626C6573002D77002D4400464F52574152445F4F55545F5A4F4E4553002D740066696C746572002D6F0074747955534232002D67004657444F5F7075626C6963 Jan 04 00:07:18 469.lan audit: NETFILTER_CFG table=filter family=10 entries=87 Jan 04 00:07:18 469.lan audit[24214]: SYSCALL arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=29 a2=40 a3=56515ddead60 items=0 ppid=1396 pid=24214 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ip6tables" exe="/usr/sbin/xtables-multi" key=(null) Jan 04 00:07:18 469.lan audit: PROCTITLE proctitle=2F7362696E2F6970367461626C6573002D77002D4400464F52574152445F4F55545F5A4F4E4553002D740066696C746572002D6F0074747955534232002D67004657444F5F7075626C6963 Jan 04 00:07:19 469.lan ModemManager[1393]: <warn> (ttyUSB2): port attributes not fully set Jan 04 00:07:20 469.lan NetworkManager[1596]: <warn> (ppp0): failed to disable userspace IPv6LL address handling Does that make any sense? There different problems here. The device is not connected to the network initially: > Nov 12 14:43:52 469.lan NetworkManager[1410]: <warn> (ttyUSB2): failed to connect modem: No cause information available > Nov 12 14:43:52 469.lan NetworkManager[1410]: <info> (ttyUSB2): device state change: prepare -> failed (reason 'modem-no-carrier') [40 120 25] The second attempt looks alright, but times out waiting for the IP address via IPCP. Not sure why that happens: > Nov 12 15:03:34 469.lan NetworkManager[13343]: <warn> pppd timed out or didn't initialize our dbus module > Nov 12 15:03:34 469.lan pppd[13472]: Terminating on signal 15 Not sure what went wrong here either... > Nov 12 15:04:59 469.lan ModemManager[13268]: <warn> Couldn't initialize PDP context with our APN: 'Sending command failed: 'Resource temporarily unavailable'' > Nov 12 15:04:59 469.lan ModemManager[13268]: <info> Modem /org/freedesktop/ModemManager1/Modem/1: state changed (connecting -> registered) > Nov 12 15:04:59 469.lan NetworkManager[13343]: <info> (ttyUSB2): modem state changed, 'connecting' --> 'registered' (reason: user-requested) > Nov 12 15:04:59 469.lan NetworkManager[13343]: <warn> (ttyUSB2): failed to connect modem: Sending command failed: 'Resource temporarily unavailable' I'm wondering if you could retest with the updated packages from here: https://bodhi.fedoraproject.org/updates/FEDORA-2016-494a721a73 Thank you, Lubo Hi Lubo, I could check that in September, I am currently traveling and I do not have this modem with me. I eventually got frustrated with the breakage and bought a modem that does the mobile internet part itself and that presents itself as a WiFi gateway ;) I'll get back to you mid-september, that's when I will have access to the modem from the bug report again. Any chance you could have a look? The updated package made it to the updates repository since. Sorry for not getting back to you earlier, I indeed returned recently and have the modem here. However, in the meantime I moved to Fedora 24, but I assume this is not a problem, I guess the updated package made it there as well? I will test the modem tonight and let you know if it works now (just beware that it's not on Fedora 23 anymore...) Created attachment 1207329 [details]
log output of journalctl -f while attempting to connect to the internet
So, here is the log.
I started ModemManager with DEBUG loglevel and saved the journalctl output.
What I did:
attached the modem
waited for it to show the available network
attempted to establish a connection (it failed)
attempted to establish a connection again (it failed)
removed the modem
The only thing removed from the log is the SMS readout/dump.
The above was done on Fedora 24, ModemManager-1.6.0-1.fc24.x86_64
Oct 04 21:18:03 469.lan pppd[21242]: Plugin /usr/lib64/pppd/2.4.7/nm-pppd-plugin.so loaded. Oct 04 21:18:03 469.lan NetworkManager[1648]: Plugin /usr/lib64/pppd/2.4.7/nm-pppd-plugin.so loaded. Oct 04 21:18:03 469.lan NetworkManager[1648]: nm-pppd-plugin-Message: nm-ppp-plugin: (plugin_init): initializing Oct 04 21:18:03 469.lan pppd[21242]: pppd 2.4.7 started by root, uid 0 Oct 04 21:18:03 469.lan NetworkManager[1648]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_phasechange): status 3 / phase 'serial connection' Oct 04 21:18:03 469.lan pppd[21242]: Baud rate for /dev/ttyUSB0 is 0; need explicit baud rate Oct 04 21:18:03 469.lan NetworkManager[1648]: Baud rate for /dev/ttyUSB0 is 0; need explicit baud rate Oct 04 21:18:04 469.lan NetworkManager[1648]: nm-pppd-plugin-Message: nm-ppp-plugin: (nm_exit_notify): cleaning up Looks like pppd complains because the port doesn't have a speed set. Which is odd, since ModemManager defaults to 57600, and with USB the baud rate actually doesn't matter at all. Could you report the output of "stty -F /dev/ttyUSB0": 1) before you try to connect 2) after the connect fails Thanks! Before: $ stty -F /dev/ttyUSB0 speed 0 baud; line = 0; eof = ^A; min = 1; time = 0; ignbrk -brkint -icrnl ixoff ixany -imaxbel -opost -onlcr -isig -icanon -iexten -echo -echoe After: $ stty -F /dev/ttyUSB0 speed 0 baud; line = 0; eof = ^A; min = 1; time = 0; ignbrk -brkint -icrnl ixoff ixany -imaxbel -opost -onlcr -isig -icanon -iexten -echo -echoe So actually same output before and after the failed connection. Thanks; the serial port likely just doesn't care about baudrate, but pppd does. What if you: nmcli con mod HoT serial.baud 57600 and then retry the connection? That may make pppd happy. Tried it, indeed, this worked, after the above command I could initiate the connection without any problems. This message is a reminder that Fedora 23 is nearing its end of life. Approximately 4 (four) weeks from now Fedora will stop maintaining and issuing updates for Fedora 23. It is Fedora's policy to close all bug reports from releases that are no longer maintained. At that time this bug will be closed as EOL if it remains open with a Fedora 'version' of '23'. Package Maintainer: If you wish for this bug to remain open because you plan to fix it in a currently maintained version, simply change the 'version' to a later Fedora version. Thank you for reporting this issue and we are sorry that we were not able to fix it before Fedora 23 is end of life. If you would still like to see this bug fixed and are able to reproduce it against a later version of Fedora, you are encouraged change the 'version' to a later Fedora version prior this bug is closed as described in the policy above. Although we aim to fix as many bugs as possible during every release's lifetime, sometimes those efforts are overtaken by events. Often a more recent Fedora release includes newer upstream software that fixes bugs or makes them obsolete. Fedora 23 changed to end-of-life (EOL) status on 2016-12-20. Fedora 23 is no longer maintained, which means that it will not receive any further security or bug fix updates. As a result we are closing this bug. If you can reproduce this bug against a currently maintained version of Fedora please feel free to reopen this bug against that version. If you are unable to reopen this bug, please file a new report against the current release. If you experience problems, please add a comment to this bug. Thank you for reporting this bug and we are sorry it could not be fixed. |