Modify

Opened 7 years ago

Last modified 3 years ago

#9211 reopened defect

3G connection doesn't start at boot.

Reported by: Crazy Owned by: developers
Priority: lowest Milestone: Bugs Paradise
Component: other Version: Trunk
Keywords: Cc:

Description

Attachments (5)

hotplug2.patch (517 bytes) - added by Layne Edwards <ledwards@…> 7 years ago.
enable hotplug of tty subsytem
base-files.patch (1.3 KB) - added by Layne Edwards <ledwards@…> 7 years ago.
update hotplug2 common rules to support tty hotplug
comgt.patch (1.7 KB) - added by Layne Edwards <ledwards@…> 7 years ago.
update 3g-hotplug and move to /etc/hotplug.d/tty
comgt-2.patch (1.3 KB) - added by Layne Edwards <ledwards@…> 7 years ago.
update 3g-hotplug to not iterate over all devices, but only the current device; created remove handler to bring down interface
usb-mode.json.custom (44.4 KB) - added by anonymous 3 years ago.
mv usb-mode.json.custom ./usb-mode-custom.json; usbmode -l; usbmode -s -v -c ./usb-mode-custom.json; #and report back here

Download all attachments as: .zip

Change History (45)

comment:1 Changed 7 years ago by anonymous

comgt already has a hotplug script to auto start 3g connection. In trunk and latest backfire (not -rc4)

comment:2 Changed 7 years ago by Crazy

I'm using r26853 (from trunk) and doesn't work.
The problem is that the interface with 3g proto is always down on boot and the only way is unplug an replug usb modem every reboot.

Test with Huawei e1820, Huawei e270 and Huawei e352

Many thanks

comment:3 Changed 7 years ago by Max

I confirm this annoying bug !
The option auto 1 is ignored for 3g proto.

comment:4 Changed 7 years ago by anonymous

Confirmed here as well with r26748 (trunk @ ar71xx)

comment:5 Changed 7 years ago by ari@…

Had the same problem with DIR-825. I fixed it by modifying /etc/hotplug.d/usb/30-3g like this:

--- orig/3g.usb	2011-04-05 17:59:45.000000000 +0300
+++ 30-3g	2011-04-05 18:01:53.000000000 +0300
@@ -35,6 +35,7 @@
 		*) exit 0;;
 	esac
 
+	sleep 2
 	local tty
 	for tty in /sys/$DEVPATH/ttyUSB* /sys/$DEVPATH/tty/ttyACM* /sys/$DEVPATH/tty/ttyHS*; do
 		[ -d "$tty" ] || continue

The problem was that when hotplug script is run the /sys/$DEVPAGH/ttyUSB files are
not present at that time (don't know why, maybe driver is still initializing someting).
Waiting 2 seconds fixes this.

My modem was Huawei E1552, I'm using backfire branch.

comment:6 Changed 7 years ago by Layne Edwards <ledwards@…>

Sometimes the tty (serial) devices take a couple of seconds to show up after the USB device is hotplugged. The /etc/hotplug.d/usb/30-3g is executed on the USB device, not the actual tty device.

Another solution for this is to move /etc/hotplug.d/usb/30-3g to /etc/hotplug.d/tty/30-3g (and update the hotplug2 rules to handle the tty subsystem). Therefore, the 30-3g script is executed on the actual tty device hotplug.

This solution is working well for me with many different 3G modems (Sierra, Option, Huawei, etc).

comment:7 Changed 7 years ago by Layne Edwards <ledwards@…>

JoW - Please test the following attached patches. This should fix the issue where the 3G interface is not automatically brought up on coldplug/hotplug. It does not address the issue of usb-modeswitch not switching on coldboot (I have another patch for this).

  • hotplug2.patch: enable tty subsystem
  • base-files.patch: update hotplug2 common rules to support tty hotplug
  • comgt.patch: update 3g-hotplug and move to /etc/hotplug.d/tty

Note: While modifying the hotplug2 common rules in order to support tty hotplug, I noticed some issues. For example, tun is created twice (i.e. /dev/tun and /dev/net/tun) and some of the file modes are being overwritten by a second makedev (i.e. ppp should be 0600 per the rule, but it is created as 0644). Another ticket should probably be created to address these issues. I cleaned it up a little bit in my patch, but I think more work could be done with /etc/hotplug2-common.rules.

Thanks,
Layne

Changed 7 years ago by Layne Edwards <ledwards@…>

enable hotplug of tty subsytem

Changed 7 years ago by Layne Edwards <ledwards@…>

update hotplug2 common rules to support tty hotplug

Changed 7 years ago by Layne Edwards <ledwards@…>

update 3g-hotplug and move to /etc/hotplug.d/tty

comment:8 Changed 7 years ago by jow

  • Resolution set to fixed
  • Status changed from new to closed

Committed in r26807, r26808 and r26809 - thanks!
Layne, can you create a separate ticket for the modeswitch coldplug issues?

comment:9 Changed 7 years ago by Layne Edwards <ledwards@…>

  • Resolution fixed deleted
  • Status changed from closed to reopened

Please consider the following patch in addition to the previous changes.

Most USB modems have multiple tty serial devices (sometimes 5 or more), and each tty triggers a hotplug event when added. Because of the for loop, each previously added device is iterated again when subsequent devices are added. This can result in multiple calls to ifup. Because the lock file is not created instantly and ifup is run in the background, multiple instances are running in parallel, which can cause problems and tie up the system. We don't need to execute ifup multiple times for the same interface.

The solution is to remove the for loop. We really only need to check the current device being added, as each device will generate it's own hotplug event.

I also added a handler for the remove action. It brings down the interface when the tty device is removed... otherwise there could be an "orphaned" pppd instance when the USB stick is yanked out.

Regards,
Layne

Changed 7 years ago by Layne Edwards <ledwards@…>

update 3g-hotplug to not iterate over all devices, but only the current device; created remove handler to bring down interface

comment:10 Changed 7 years ago by jow

  • Resolution set to fixed
  • Status changed from reopened to closed

Changes incorperated in r26816 - I simplified the code as well.

comment:11 Changed 6 years ago by anonymous

  • Resolution fixed deleted
  • Status changed from closed to reopened

this fix doesn't work on backfire 10.03.1-rc6 with kernel 2.4
The 3g connection doesn't start on boot.

comment:12 Changed 6 years ago by jow

  • Priority changed from normal to response-needed

Your configuration? Your log?

comment:13 Changed 6 years ago by anonymous

I installed Backfire (10.03.1, r29508) kernel 2.4 on d-link dir-320.

These are my installed packages:

root@DIR-320:~# opkg list_installed
base-files - 43.31-r29508
busybox - 1.15.3-3.4
chat - 2.4.4-16.1
comgt - 0.32-9
ddns-scripts - 1.0.0-17
dnsmasq - 2.55-6
dropbear - 0.53.1-5
firewall - 2-34.7
hotplug2 - 1.0-beta-3
iptables - 1.4.6-3.1
iptables-mod-conntrack - 1.4.6-3.1
iptables-mod-nat - 1.4.6-3.1
kernel - 2.4.37.9-1
kmod-brcm-wl - 2.4.37.9+4.150.10.5.3-9
kmod-diag - 2.4.37.9-7.1
kmod-ipt-conntrack - 2.4.37.9-1
kmod-ipt-core - 2.4.37.9-1
kmod-ipt-nat - 2.4.37.9-1
kmod-ipt-nathelper - 2.4.37.9-1
kmod-ppp - 2.4.37.9-1
kmod-pppoe - 2.4.37.9-1
kmod-switch - 2.4.37.9-4
kmod-usb-core - 2.4.37.9-1
kmod-usb-ohci - 2.4.37.9-1
kmod-usb-serial - 2.4.37.9-1
kmod-usb2 - 2.4.37.9-1
kmod-wlcompat - 2.4.37.9+4.150.10.5.3-9
libc - 0.9.30.1-43.31
libgcc - 3.4.6-43.31
libip4tc - 1.4.6-3.1
libiwinfo - 18
libiwinfo-lua - 18
liblua - 5.1.4-7
libncurses - 5.7-2
librt - 0.9.30.1-43.31
libuci - 12012009.7-4
libuci-lua - 12012009.7-4
libxtables - 1.4.6-3.1
lua - 5.1.4-7
luci - 0.10+svn8086-1
luci-app-ddns - 0.10+svn8086-1
luci-app-firewall - 0.10+svn8086-1
luci-app-ntpc - 0.10+svn8086-1
luci-i18n-english - 0.10+svn8086-1
luci-lib-core - 0.10+svn8086-1
luci-lib-ipkg - 0.10+svn8086-1
luci-lib-lmo - 0.10+svn8086-1
luci-lib-nixio - 0.10+svn8086-1
luci-lib-sys - 0.10+svn8086-1
luci-lib-web - 0.10+svn8086-1
luci-mod-admin-core - 0.10+svn8086-1
luci-mod-admin-full - 0.10+svn8086-1
luci-proto-3g - 0.10+svn8086-1
luci-proto-core - 0.10+svn8086-1
luci-proto-ppp - 0.10+svn8086-1
luci-sgi-cgi - 0.10+svn8086-1
luci-theme-base - 0.10+svn8086-1
luci-theme-openwrt - 0.10+svn8086-1
mtd - 13
nano - 2.2.6-1
nas - 4.150.10.5.3-9
ntpclient - 2007_365-4
nvram - 7
opkg - 576-2
ppp - 2.4.4-16.1
ppp-mod-pppoe - 2.4.4-16.1
uci - 12012009.7-4
uhttpd - 28
wireless-tools - 29-4
wl - 4.150.10.5.3-9
wlc - 4.150.10.5.3-9

This is my network config:

root@DIR-320:~# cat /etc/config/network 

config 'switch' 'eth0'
	option 'enable' '1'

config 'switch_vlan' 'eth0_0'
	option 'device' 'eth0'
	option 'vlan' '0'
	option 'ports' '0 1 2 3 4 5'

config 'interface' 'loopback'
	option 'ifname' 'lo'
	option 'proto' 'static'
	option 'ipaddr' '127.0.0.1'
	option 'netmask' '255.0.0.0'

config 'interface' 'lan'
	option 'type' 'bridge'
	option 'ifname' 'eth0.0'
	option 'proto' 'static'
	option 'ipaddr' '192.168.1.1'
	option 'netmask' '255.255.255.0'

config 'interface' 'wan'		
	option 'proto' '3g'
	option 'device' '/dev/usb/tts/0'
	option 'service' 'umts'
	option 'apn' 'internet.wind'
	option 'peerdns' '0'
	option 'dns' '8.8.8.8 208.67.222.222 8.8.4.4 208.67.220.220'

This is dmesg after boot:

root@DIR-320:~# dmesg        
CPU revision is: 00029029
Primary instruction cache 16kB, physically tagged, 4-way, linesize 16 bytes.
Primary data cache 16kB, 2-way, linesize 16 bytes.
Linux version 2.4.37.9 (wizard@Linux-D3sk) (gcc version 3.4.6 (OpenWrt-2.0)) #3 Tue Dec 13 11:24:24 CET 2011
Setting the PFC to its default value
Determined physical RAM map:
 memory: 02000000 @ 00000000 (usable)
On node 0 totalpages: 8192
zone(0): 8192 pages.
zone(1): 0 pages.
zone(2): 0 pages.
Kernel command line: root=/dev/mtdblock2 rootfstype=squashfs,jffs2 init=/etc/preinit noinitrd console=ttyS0,115200
CPU: BCM5354 rev 3 at 240 MHz
Using 120.000 MHz high precision timer.
Calibrating delay loop... 237.56 BogoMIPS
Memory: 30460k/32768k available (1439k kernel code, 2308k reserved, 96k data, 84k init, 0k highmem)
Dentry cache hash table entries: 4096 (order: 3, 32768 bytes)
Inode cache hash table entries: 2048 (order: 2, 16384 bytes)
Mount cache hash table entries: 512 (order: 0, 4096 bytes)
Buffer cache hash table entries: 1024 (order: 0, 4096 bytes)
Page-cache hash table entries: 8192 (order: 3, 32768 bytes)
Checking for 'wait' instruction...  unavailable.
POSIX conformance testing by UNIFIX
PCI: no core
PCI: Fixing up bus 0
Linux NET4.0 for Linux 2.4
Based upon Swansea University Computer Society NET3.039
Initializing RT netlink socket
Starting kswapd
Registering mini_fo version $Id$
devfs: v1.12c (20020818) Richard Gooch (rgooch@atnf.csiro.au)
devfs: boot_options: 0x1
JFFS2 version 2.1. (C) 2001 Red Hat, Inc., designed by Axis Communications AB.
squashfs: version 3.0 (2006/03/15) Phillip Lougher
pty: 256 Unix98 ptys configured
Serial driver version 5.05c (2001-07-08) with MANY_PORTS SHARE_IRQ SERIAL_PCI enabled
ttyS00 at 0xb8000300 (irq = 3) is a 16550A
ttyS01 at 0xb8000400 (irq = 3) is a 16550A
b44.c:v0.93 (Mar, 2004)
PCI: Setting latency timer of device 00:01.0 to 64
eth0: Broadcom 47xx 10/100BaseT Ethernet 00:90:4c:c0:00:00
Physically mapped flash: Found an alias at 0x400000 for the chip at 0x0
Physically mapped flash: Found an alias at 0x800000 for the chip at 0x0
Physically mapped flash: Found an alias at 0xc00000 for the chip at 0x0
Physically mapped flash: Found an alias at 0x1000000 for the chip at 0x0
Physically mapped flash: Found an alias at 0x1400000 for the chip at 0x0
Physically mapped flash: Found an alias at 0x1800000 for the chip at 0x0
Physically mapped flash: Found an alias at 0x1c00000 for the chip at 0x0
 Amd/Fujitsu Extended Query Table v1.1 at 0x0040
Physically mapped flash: Swapping erase regions for broken CFI table.
number of CFI chips: 1
cfi_cmdset_0002: Disabling fast programming due to code brokenness.
Flash device: 0x400000 at 0x1c000000
bootloader size: 262144
Physically mapped flash: Filesystem type: squashfs, size=0x1f4a6b
Creating 5 MTD partitions on "Physically mapped flash":
0x00000000-0x00040000 : "cfe"
0x00040000-0x003f0000 : "linux"
0x000bb400-0x002b0000 : "rootfs"
mtd: partition "rootfs" doesn't start on an erase block boundary -- force read-only
0x003f0000-0x00400000 : "nvram"
0x002b0000-0x003f0000 : "rootfs_data"
sflash: found no supported devices
Initializing Cryptographic API
NET4: Linux TCP/IP 1.0 for NET4.0
IP Protocols: ICMP, UDP, TCP, IGMP
IP: routing cache hash table of 512 buckets, 4Kbytes
TCP: Hash tables configured (established 2048 bind 4096)
Linux IP multicast router 0.06 plus PIM-SM
NET4: Unix domain sockets 1.0/SMP for Linux NET4.0.
NET4: Ethernet Bridge 008 for NET4.0
802.1Q VLAN Support v1.8 Ben Greear <greearb@candelatech.com>
All bugs added by David S. Miller <davem@redhat.com>
VFS: Mounted root (squashfs filesystem) readonly.
Mounted devfs on /dev
Freeing unused kernel memory: 84k freed
diag: Detected 'D-Link DIR-320'
b44: eth0: Link is up at 100 Mbps, full duplex.
b44: eth0: Flow control is off for TX and off for RX.
roboswitch: Probing device eth0: found a 5325! It's a 5350.
mini_fo: using base directory: /
mini_fo: using storage directory: /overlay
jffs2.bbc: SIZE compression mode activated.
b44: eth0: Link is up at 100 Mbps, full duplex.
b44: eth0: Flow control is off for TX and off for RX.
usb.c: registered new driver usbdevfs
usb.c: registered new driver hub
eth0.0: add 01:00:5e:00:00:01 mcast address to master interface
eth0.0: dev_set_promiscuity(master, 1)
device eth0 entered promiscuous mode
device eth0.0 entered promiscuous mode
br-lan: port 1(eth0.0) entering learning state
br-lan: port 1(eth0.0) entering forwarding state
br-lan: topology change detected, propagating
PCI: Setting latency timer of device 00:05.0 to 64
PCI/DMA
wl0: wlc_attach: chiprev 3 coreunit 0 corerev 13 cccap 0x104007ea maccap 0x30482205 band 2.4G, phy_type 5 phy_rev 0 ana_rev 6
wl0: Broadcom BCM4318 802.11 Wireless Controller 4.150.10.5
CSLIP: code copyright 1989 Regents of the University of California
PPP generic driver version 2.4.2
ip_tables: (C) 2000-2002 Netfilter core team
SB USB20H init
SB COREREV: 2
SB USB20H resetting
USB20H fcr: 0x64
USB20H shim cr: 0x8f7
PCI: Setting latency timer of device 00:03.1 to 64
ehci_hcd 00:03.1: PCI device 14e4:471a
ehci_hcd 00:03.1: irq 6, pci mem b8003800
usb.c: new USB bus registered, assigned bus number 1
ehci_hcd 00:03.1: illegal capability!
ehci_hcd 00:03.1: USB 0.0 enabled, EHCI 1.00, driver 2003-Dec-29/2.4
hub.c: USB hub found
hub.c: 2 ports detected
ip_conntrack version 2.1 (5953 buckets, 5953 max) - 336 bytes per conntrack
hub.c: new USB device 00:03.1-1, assigned address 2
usb.c: USB device 2 (vend/prod 0x12d1/0x1001) is not claimed by any active driver.
SB USB20H init
SB COREREV: 2
USB20H fcr: 0x64
USB20H shim cr: 0x8f7
PCI: Setting latency timer of device 00:03.0 to 64
usb-ohci.c: USB OHCI at membase 0xb8003000, IRQ 6
usb-ohci.c: usb-00:03.0, PCI device 14e4:471a
usb.c: new USB bus registered, assigned bus number 2
hub.c: USB hub found
hub.c: 2 ports detected
usb.c: registered new driver serial
usbserial.c: USB Serial support registered for Generic
usbserial.c: Generic converter detected
usbserial.c: Generic converter now attached to ttyUSB0 (or usb/tts/0 for devfs)
usbserial.c: Generic converter detected
usbserial.c: Generic converter now attached to ttyUSB1 (or usb/tts/1 for devfs)
usbserial.c: Generic converter detected
usbserial.c: Generic converter now attached to ttyUSB2 (or usb/tts/2 for devfs)
usbserial.c: USB Serial Driver core v1.4
device wl0 entered promiscuous mode
br-lan: port 2(wl0) entering learning state
br-lan: port 2(wl0) entering forwarding state
br-lan: topology change detected, propagating

This is logread after boot:

root@DIR-320:~# logread 
Dec 15 09:22:00 DIR-320 syslog.info syslogd started: BusyBox v1.15.3
Dec 15 09:22:00 DIR-320 user.notice kernel: klogd started: BusyBox v1.15.3 (2011-12-13 11:16:38 CET)
Dec 15 09:22:00 DIR-320 user.warn kernel: CPU revision is: 00029029
Dec 15 09:22:00 DIR-320 user.warn kernel: Primary instruction cache 16kB, physically tagged, 4-way, linesize 16 bytes.
Dec 15 09:22:00 DIR-320 user.warn kernel: Primary data cache 16kB, 2-way, linesize 16 bytes.
Dec 15 09:22:00 DIR-320 user.warn kernel: Linux version 2.4.37.9 (wizard@Linux-D3sk) (gcc version 3.4.6 (OpenWrt-2.0)) #3 Tue Dec 13 11:24:24 CET 2011
Dec 15 09:22:00 DIR-320 user.warn kernel: Setting the PFC to its default value
Dec 15 09:22:00 DIR-320 user.warn kernel: Determined physical RAM map:
Dec 15 09:22:00 DIR-320 user.warn kernel:  memory: 02000000 @ 00000000 (usable)
Dec 15 09:22:00 DIR-320 user.warn kernel: On node 0 totalpages: 8192
Dec 15 09:22:00 DIR-320 user.warn kernel: zone(0): 8192 pages.
Dec 15 09:22:00 DIR-320 user.warn kernel: zone(1): 0 pages.
Dec 15 09:22:00 DIR-320 user.warn kernel: Checking for 'wait' instruction...  unavailable.
Dec 15 09:22:00 DIR-320 user.warn kernel: POSIX conformance testing by UNIFIX
Dec 15 09:22:00 DIR-320 user.warn kernel: PCI: no core
Dec 15 09:22:00 DIR-320 user.warn kernel: PCI: Fixing up bus 0
Dec 15 09:22:00 DIR-320 user.info kernel: Linux NET4.0 for Linux 2.4
Dec 15 09:22:00 DIR-320 user.info kernel: Based upon Swansea University Computer Society NET3.039
Dec 15 09:22:00 DIR-320 user.warn kernel: Initializing RT netlink socket
Dec 15 09:22:00 DIR-320 user.warn kernel: Starting kswapd
Dec 15 09:22:00 DIR-320 user.warn kernel: Registering mini_fo version $Id$
Dec 15 09:22:00 DIR-320 user.info kernel: devfs: v1.12c (20020818) Richard Gooch (rgooch@atnf.csiro.au)
Dec 15 09:22:00 DIR-320 user.info kernel: devfs: boot_options: 0x1
Dec 15 09:22:02 DIR-320 user.info kernel: b44: eth0: Link is up at 100 Mbps, full duplex.
Dec 15 09:22:02 DIR-320 user.info kernel: b44: eth0: Flow control is off for TX and off for RX.
Dec 15 09:22:03 DIR-320 user.info kernel: usb.c: registered new driver usbdevfs
Dec 15 09:22:03 DIR-320 user.info kernel: usb.c: registered new driver hub
Dec 15 09:22:03 DIR-320 user.debug kernel: eth0.0: add 01:00:5e:00:00:01 mcast address to master interface
Dec 15 09:22:04 DIR-320 user.notice ifup: Enabling Router Solicitations on loopback (lo)
Dec 15 09:22:04 DIR-320 user.info kernel: eth0.0: dev_set_promiscuity(master, 1)
Dec 15 09:22:04 DIR-320 user.info kernel: device eth0 entered promiscuous mode
Dec 15 09:22:04 DIR-320 user.info kernel: device eth0.0 entered promiscuous mode
Dec 15 09:22:04 DIR-320 user.info kernel: br-lan: port 1(eth0.0) entering learning state
Dec 15 09:22:04 DIR-320 user.info kernel: br-lan: port 1(eth0.0) entering forwarding state
Dec 15 09:22:04 DIR-320 user.info kernel: br-lan: topology change detected, propagating
Dec 15 09:22:06 DIR-320 user.info sysinit: 0.openwrt.pool.ntp.org: Unknown host
Dec 15 09:22:06 DIR-320 user.info sysinit: 1.openwrt.pool.ntp.org: Unknown host
Dec 15 09:22:06 DIR-320 user.info sysinit: 2.openwrt.pool.ntp.org: Unknown host
Dec 15 09:22:06 DIR-320 user.info sysinit: 3.openwrt.pool.ntp.org: Unknown host
Dec 15 09:22:06 DIR-320 user.debug kernel: PCI: Setting latency timer of device 00:05.0 to 64
Dec 15 09:22:06 DIR-320 user.emerg kernel: PCI/DMA
Dec 15 09:22:06 DIR-320 user.emerg kernel: wl0: wlc_attach: chiprev 3 coreunit 0 corerev 13 cccap 0x104007ea maccap 0x30482205 band 2.4G, phy_type 5 phy_rev 0 ana_rev 6
Dec 15 09:22:06 DIR-320 user.warn kernel: wl0: Broadcom BCM4318 802.11 Wireless Controller 4.150.10.5
Dec 15 09:22:06 DIR-320 user.info sysinit: Warning: loading wl will taint the kernel: non-GPL license - Proprietary
Dec 15 09:22:06 DIR-320 user.info sysinit:   See http://www.tux.org/lkml/#export-tainted for information about tainted modules
Dec 15 09:22:06 DIR-320 user.info kernel: CSLIP: code copyright 1989 Regents of the University of California
Dec 15 09:22:07 DIR-320 user.info kernel: PPP generic driver version 2.4.2
Dec 15 09:22:07 DIR-320 user.warn kernel: ip_tables: (C) 2000-2002 Netfilter core team
Dec 15 09:22:08 DIR-320 user.notice ifup: Enabling Router Solicitations on lan (br-lan)
Dec 15 09:22:08 DIR-320 user.info kernel: SB USB20H init
Dec 15 09:22:08 DIR-320 user.info kernel: SB COREREV: 2
Dec 15 09:22:08 DIR-320 user.info kernel: SB USB20H resetting
Dec 15 09:22:08 DIR-320 user.info kernel: USB20H fcr: 0x64
Dec 15 09:22:08 DIR-320 user.info kernel: USB20H shim cr: 0x8f7
Dec 15 09:22:08 DIR-320 user.debug kernel: PCI: Setting latency timer of device 00:03.1 to 64
Dec 15 09:22:08 DIR-320 user.info kernel: ehci_hcd 00:03.1: PCI device 14e4:471a
Dec 15 09:22:08 DIR-320 user.info kernel: ehci_hcd 00:03.1: irq 6, pci mem b8003800
Dec 15 09:22:08 DIR-320 user.info kernel: usb.c: new USB bus registered, assigned bus number 1
Dec 15 09:22:08 DIR-320 user.warn kernel: ehci_hcd 00:03.1: illegal capability!
Dec 15 09:22:08 DIR-320 user.info kernel: ehci_hcd 00:03.1: USB 0.0 enabled, EHCI 1.00, driver 2003-Dec-29/2.4
Dec 15 09:22:09 DIR-320 user.info kernel: hub.c: USB hub found
Dec 15 09:22:09 DIR-320 user.info kernel: hub.c: 2 ports detected
Dec 15 09:22:09 DIR-320 user.warn kernel: ip_conntrack version 2.1 (5953 buckets, 5953 max) - 336 bytes per conntrack
Dec 15 09:22:09 DIR-320 user.info kernel: hub.c: new USB device 00:03.1-1, assigned address 2
Dec 15 09:22:09 DIR-320 user.warn kernel: usb.c: USB device 2 (vend/prod 0x12d1/0x1001) is not claimed by any active driver.
Dec 15 09:22:10 DIR-320 user.info kernel: SB USB20H init
Dec 15 09:22:10 DIR-320 user.info kernel: SB COREREV: 2
Dec 15 09:22:10 DIR-320 user.info kernel: USB20H fcr: 0x64
Dec 15 09:22:10 DIR-320 user.info kernel: USB20H shim cr: 0x8f7
Dec 15 09:22:10 DIR-320 user.debug kernel: PCI: Setting latency timer of device 00:03.0 to 64
Dec 15 09:22:10 DIR-320 user.info kernel: usb-ohci.c: USB OHCI at membase 0xb8003000, IRQ 6
Dec 15 09:22:10 DIR-320 user.info kernel: usb-ohci.c: usb-00:03.0, PCI device 14e4:471a
Dec 15 09:22:10 DIR-320 user.info kernel: usb.c: new USB bus registered, assigned bus number 2
Dec 15 09:22:10 DIR-320 user.info kernel: hub.c: USB hub found
Dec 15 09:22:10 DIR-320 user.info kernel: hub.c: 2 ports detected
Dec 15 09:22:11 DIR-320 user.info kernel: usb.c: registered new driver serial
Dec 15 09:22:11 DIR-320 user.info kernel: usbserial.c: USB Serial support registered for Generic
Dec 15 09:22:11 DIR-320 user.info kernel: usbserial.c: Generic converter detected
Dec 15 09:22:11 DIR-320 user.info kernel: usbserial.c: Generic converter now attached to ttyUSB0 (or usb/tts/0 for devfs)
Dec 15 09:22:11 DIR-320 user.info kernel: usbserial.c: Generic converter detected
Dec 15 09:22:11 DIR-320 user.info kernel: usbserial.c: Generic converter now attached to ttyUSB1 (or usb/tts/1 for devfs)
Dec 15 09:22:11 DIR-320 user.info kernel: usbserial.c: Generic converter detected
Dec 15 09:22:11 DIR-320 user.info kernel: usbserial.c: Generic converter now attached to ttyUSB2 (or usb/tts/2 for devfs)
Dec 15 09:22:11 DIR-320 user.info kernel: usbserial.c: USB Serial Driver core v1.4
Dec 15 09:22:13 DIR-320 user.info kernel: device wl0 entered promiscuous mode
Dec 15 09:22:13 DIR-320 user.info kernel: br-lan: port 2(wl0) entering learning state
Dec 15 09:22:13 DIR-320 user.info kernel: br-lan: port 2(wl0) entering forwarding state
Dec 15 09:22:13 DIR-320 user.info kernel: br-lan: topology change detected, propagating
Dec 15 09:22:16 DIR-320 user.info sysinit: Loading defaults
Dec 15 09:22:16 DIR-320 user.info sysinit: Loading synflood protection
Dec 15 09:22:17 DIR-320 user.info sysinit: Adding custom chains
Dec 15 09:22:18 DIR-320 user.info sysinit: Loading zones
Dec 15 09:22:20 DIR-320 user.info sysinit: Loading forwardings
Dec 15 09:22:20 DIR-320 user.info sysinit: Loading redirects
Dec 15 09:22:20 DIR-320 user.info sysinit: Loading rules
Dec 15 09:22:20 DIR-320 user.info sysinit: Loading includes
Dec 15 09:22:21 DIR-320 user.info sysinit: Optimizing conntrack
Dec 15 09:22:21 DIR-320 user.info sysinit: Loading interfaces
Dec 15 09:22:21 DIR-320 user.info firewall: adding lan (br-lan) to zone lan
Dec 15 09:22:23 DIR-320 authpriv.info dropbear[693]: Running in background
Dec 15 09:22:24 DIR-320 user.notice dnsmasq: DNS rebinding protection is active, will discard upstream RFC1918 responses!
Dec 15 09:22:24 DIR-320 user.notice dnsmasq: Allowing 127.0.0.0/8 responses
Dec 15 09:22:27 DIR-320 daemon.info dnsmasq[722]: started, version 2.55 cachesize 150
Dec 15 09:22:27 DIR-320 daemon.info dnsmasq[722]: compile time options: IPv6 GNU-getopt no-DBus no-I18N DHCP TFTP
Dec 15 09:22:27 DIR-320 daemon.info dnsmasq-dhcp[722]: DHCP, IP range 192.168.1.100 -- 192.168.1.250, lease time 12h
Dec 15 09:22:27 DIR-320 daemon.info dnsmasq[722]: using local addresses only for domain lan
Dec 15 09:22:27 DIR-320 daemon.warn dnsmasq[722]: no servers found in /tmp/resolv.conf.auto, will retry
Dec 15 09:22:27 DIR-320 daemon.info dnsmasq[722]: read /etc/hosts - 1 addresses
Dec 15 09:22:27 DIR-320 daemon.info dnsmasq-dhcp[722]: read /etc/ethers - 0 addresses
Dec 15 09:22:35 DIR-320 authpriv.info dropbear[734]: Child connection from 192.168.1.24:44011
Dec 15 09:22:40 DIR-320 authpriv.notice dropbear[734]: Password auth succeeded for 'root' from 192.168.1.24:44011

This is ps after boot:

root@DIR-320:~# ps
  PID USER       VSZ STAT COMMAND
    1 root      1432 S    init       
    2 root         0 SW   [keventd]
    3 root         0 RWN  [ksoftirqd_CPU0]
    4 root         0 SW   [kswapd]
    5 root         0 SW   [bdflush]
    6 root         0 SW   [kupdated]
    8 root         0 SW   [mtdblockd]
   94 root         0 SWN  [jffs2_gcd_mtd4]
  120 root      1432 S    init       
  145 root      1440 S    syslogd -C16 
  147 root      1424 S    klogd 
  160 root       712 S    /sbin/hotplug2 --override --persistent --set-worker /
  241 root         0 SW   [khubd]
  504 root       888 S    /usr/sbin/nas -P /var/run/nas.wl0.pid -H 34954 -l br-
  693 root      1108 S    /usr/sbin/dropbear -P /var/run/dropbear.1.pid -p 22 
  701 root       944 S    /usr/sbin/uhttpd -f -h /www -r DIR-320 -x /cgi-bin -t
  722 nobody     868 S    /usr/sbin/dnsmasq -K -D -y -Z -b -E -s lan -S /lan/ -
  731 root      1432 S    /usr/sbin/ntpd -n -p 0.openwrt.pool.ntp.org -p 1.open
  734 root      1184 S    /usr/sbin/dropbear -P /var/run/dropbear.1.pid -p 22 
  735 root      1440 S    -ash 
  743 root      1428 R    ps 

Then if I issue manually ifup wan, this is logread:

Dec 15 09:25:47 DIR-320 daemon.notice pppd[807]: pppd 2.4.4 started by root, uid 0
Dec 15 09:25:49 DIR-320 local2.info chat[810]: abort on (BUSY)
Dec 15 09:25:49 DIR-320 local2.info chat[810]: abort on (NO CARRIER)
Dec 15 09:25:49 DIR-320 local2.info chat[810]: abort on (ERROR)
Dec 15 09:25:49 DIR-320 local2.info chat[810]: report (CONNECT)
Dec 15 09:25:49 DIR-320 local2.info chat[810]: timeout set to 10 seconds
Dec 15 09:25:49 DIR-320 local2.info chat[810]: send (AT&F^M)
Dec 15 09:25:49 DIR-320 local2.info chat[810]: expect (OK)
Dec 15 09:25:49 DIR-320 local2.info chat[810]: AT&F^M^M
Dec 15 09:25:49 DIR-320 local2.info chat[810]: OK
Dec 15 09:25:49 DIR-320 local2.info chat[810]:  -- got it
Dec 15 09:25:49 DIR-320 local2.info chat[810]: send (ATE1^M)
Dec 15 09:25:49 DIR-320 local2.info chat[810]: expect (OK)
Dec 15 09:25:49 DIR-320 local2.info chat[810]: ^M
Dec 15 09:25:49 DIR-320 local2.info chat[810]: ATE1^M^M
Dec 15 09:25:49 DIR-320 local2.info chat[810]: OK
Dec 15 09:25:49 DIR-320 local2.info chat[810]:  -- got it
Dec 15 09:25:49 DIR-320 local2.info chat[810]: send (AT+CGDCONT=1,"IP","internet.wind"^M)
Dec 15 09:25:49 DIR-320 local2.info chat[810]: timeout set to 30 seconds
Dec 15 09:25:49 DIR-320 local2.info chat[810]: expect (OK)
Dec 15 09:25:49 DIR-320 local2.info chat[810]: ^M
....

ps after manual ifup wan:

root@DIR-320:~# ps
  PID USER       VSZ STAT COMMAND
    1 root      1432 S    init       
    2 root         0 SW   [keventd]
    3 root         0 RWN  [ksoftirqd_CPU0]
    4 root         0 SW   [kswapd]
    5 root         0 SW   [bdflush]
    6 root         0 SW   [kupdated]
    8 root         0 SW   [mtdblockd]
   94 root         0 SWN  [jffs2_gcd_mtd4]
  120 root      1432 S    init       
  145 root      1440 S    syslogd -C16 
  147 root      1424 S    klogd 
  160 root       712 S    /sbin/hotplug2 --override --persistent --set-worker /
  241 root         0 SW   [khubd]
  504 root       888 S    /usr/sbin/nas -P /var/run/nas.wl0.pid -H 34954 -l br-
  693 root      1108 S    /usr/sbin/dropbear -P /var/run/dropbear.1.pid -p 22 
  701 root       944 S    /usr/sbin/uhttpd -f -h /www -r DIR-320 -x /cgi-bin -t
  722 nobody     868 S    /usr/sbin/dnsmasq -K -D -y -Z -b -E -s lan -S /lan/ -
  731 root      1432 S    /usr/sbin/ntpd -n -p 0.openwrt.pool.ntp.org -p 1.open
  734 root      1184 R    /usr/sbin/dropbear -P /var/run/dropbear.1.pid -p 22 
  735 root      1440 S    -ash 
  807 root      1236 S    /usr/sbin/pppd noaccomp nopcomp novj nobsdcomp noauth
  814 root      1428 R    ps 

And then the connection is up.
Also note that if removing the internet key, the ppp process is not stopped, because I think hotplug event is not caught.
If I insert the internet key after boot is completed, the problem is the same: a manual ifup wan is required.

Regards

comment:14 Changed 6 years ago by anonymous

any news on this?

comment:15 Changed 6 years ago by nbd

  • Resolution set to fixed
  • Status changed from reopened to closed

fixed in current trunk

comment:16 Changed 6 years ago by Massy

  • Resolution fixed deleted
  • Status changed from closed to reopened

Seems not working on MR3420 and r32468

Jun 20 19:24:05 OpenWrt kern.debug kernel: [    0.000000] MyLoader: sysp=f0f0f0f0, boardp=f0f0f0f0, parts=f0f0f0f0
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.000000] bootconsole [early0] enabled
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.000000] CPU revision is: 00019374 (MIPS 24Kc)
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.000000] SoC: Atheros AR7241 rev 1
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.000000] Clocks: CPU:400.000MHz, DDR:400.000MHz, AHB:200.000MHz, Ref:5.000MHz
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.000000] Determined physical RAM map:
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.000000]  memory: 02000000 @ 00000000 (usable)
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.000000] Initrd not found or empty - disabling initrd
Jun 20 19:24:05 OpenWrt kern.warn kernel: [    0.000000] Zone PFN ranges:
Jun 20 19:24:05 OpenWrt kern.warn kernel: [    0.000000]   Normal   0x00000000 -> 0x00002000
Jun 20 19:24:05 OpenWrt kern.warn kernel: [    0.000000] Movable zone start PFN for each node
Jun 20 19:24:05 OpenWrt kern.warn kernel: [    0.000000] Early memory PFN ranges
Jun 20 19:24:05 OpenWrt kern.warn kernel: [    0.000000]     0: 0x00000000 -> 0x00002000
Jun 20 19:24:05 OpenWrt kern.debug kernel: [    0.000000] On node 0 totalpages: 8192
Jun 20 19:24:05 OpenWrt kern.debug kernel: [    0.000000] free_area_init_node: node 0, pgdat 802cd520, node_mem_map 81000000
Jun 20 19:24:05 OpenWrt kern.debug kernel: [    0.000000]   Normal zone: 64 pages used for memmap
Jun 20 19:24:05 OpenWrt kern.debug kernel: [    0.000000]   Normal zone: 0 pages reserved
Jun 20 19:24:05 OpenWrt kern.debug kernel: [    0.000000]   Normal zone: 8128 pages, LIFO batch:0
Jun 20 19:24:05 OpenWrt kern.debug kernel: [    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
Jun 20 19:24:05 OpenWrt kern.debug kernel: [    0.000000] pcpu-alloc: [0] 0 
Jun 20 19:24:05 OpenWrt kern.warn kernel: [    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 8128
Jun 20 19:24:05 OpenWrt kern.notice kernel: [    0.000000] Kernel command line:  board=TL-MR3420 console=ttyS0,115200 rootfstype=squashfs,jffs2 noinitrd
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.000000] PID hash table entries: 128 (order: -3, 512 bytes)
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.000000] Dentry cache hash table entries: 4096 (order: 2, 16384 bytes)
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.000000] Inode-cache hash table entries: 2048 (order: 1, 8192 bytes)
Jun 20 19:24:05 OpenWrt kern.warn kernel: [    0.000000] Primary instruction cache 64kB, VIPT, 4-way, linesize 32 bytes.
Jun 20 19:24:05 OpenWrt kern.warn kernel: [    0.000000] Primary data cache 32kB, 4-way, VIPT, cache aliases, linesize 32 bytes
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.000000] Writing ErrCtl register=00000000
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.000000] Readback ErrCtl register=00000000
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.000000] Memory: 29288k/32768k available (2089k kernel code, 3480k reserved, 397k data, 200k init, 0k highmem)
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.000000] SLUB: Genslabs=9, HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.000000] NR_IRQS:48
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.000000] Calibrating delay loop... 265.42 BogoMIPS (lpj=1327104)
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.080000] pid_max: default: 32768 minimum: 301
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.080000] Mount-cache hash table entries: 512
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.090000] NET: Registered protocol family 16
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.090000] gpiochip_add: registered GPIOs 0 to 17 on device: ath79
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.100000] MIPS: machine is TP-LINK TL-MR3420
Jun 20 19:24:05 OpenWrt kern.warn kernel: [    0.500000] registering PCI controller with io_map_base unset
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.540000] bio: create slab <bio-0> at 0
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.550000] PCI host bridge to bus 0000:00
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.550000] pci_bus 0000:00: root bus resource [mem 0x10000000-0x17ffffff]
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.560000] pci_bus 0000:00: root bus resource [io  0x0000]
Jun 20 19:24:05 OpenWrt kern.debug kernel: [    0.560000] pci 0000:00:00.0: [168c:002e] type 0 class 0x000280
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.560000] pci 0000:00:00.0: fixup device configuration
Jun 20 19:24:05 OpenWrt kern.debug kernel: [    0.570000] pci 0000:00:00.0: reg 10: [mem 0x10000000-0x1000ffff 64bit]
Jun 20 19:24:05 OpenWrt kern.debug kernel: [    0.570000] pci 0000:00:00.0: supports D1
Jun 20 19:24:05 OpenWrt kern.debug kernel: [    0.570000] pci 0000:00:00.0: PME# supported from D0 D1 D3hot
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.570000] pci 0000:00:00.0: BAR 0: assigned [mem 0x10000000-0x1000ffff 64bit]
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.570000] pci 0000:00:00.0: using irq 40 for pin 1
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.580000] Switching to clocksource MIPS
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.580000] NET: Registered protocol family 2
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.590000] IP route cache hash table entries: 1024 (order: 0, 4096 bytes)
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.590000] TCP established hash table entries: 1024 (order: 1, 8192 bytes)
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.600000] TCP bind hash table entries: 1024 (order: 0, 4096 bytes)
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.600000] TCP: Hash tables configured (established 1024 bind 1024)
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.610000] TCP reno registered
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.610000] UDP hash table entries: 256 (order: 0, 4096 bytes)
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.620000] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.630000] NET: Registered protocol family 1
Jun 20 19:24:05 OpenWrt kern.debug kernel: [    0.630000] PCI: CLS 0 bytes, default 32
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.650000] squashfs: version 4.0 (2009/01/31) Phillip Lougher
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.650000] JFFS2 version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.660000] msgmni has been set to 57
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.670000] io scheduler noop registered
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.670000] io scheduler deadline registered (default)
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.680000] Serial: 8250/16550 driver, 1 ports, IRQ sharing disabled
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.710000] serial8250.0: ttyS0 at MMIO 0x18020000 (irq = 11) is a 16550A
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.710000] console [ttyS0] enabled, bootconsole disabled
Jun 20 19:24:05 OpenWrt kern.warn kernel: [    0.730000] m25p80 spi0.0: found s25sl032a, expected m25p80
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.730000] m25p80 spi0.0: s25sl032a (4096 Kbytes)
Jun 20 19:24:05 OpenWrt kern.notice kernel: [    0.740000] 5 tp-link partitions found on MTD device spi0.0
Jun 20 19:24:05 OpenWrt kern.notice kernel: [    0.740000] Creating 5 MTD partitions on "spi0.0":
Jun 20 19:24:05 OpenWrt kern.notice kernel: [    0.750000] 0x000000000000-0x000000020000 : "u-boot"
Jun 20 19:24:05 OpenWrt kern.notice kernel: [    0.760000] 0x000000020000-0x0000000ffe00 : "kernel"
Jun 20 19:24:05 OpenWrt kern.warn kernel: [    0.760000] mtd: partition "kernel" must either start or end on erase block boundary or be smaller than an erase block -- forcing read-only
Jun 20 19:24:05 OpenWrt kern.notice kernel: [    0.770000] 0x0000000ffe00-0x0000003f0000 : "rootfs"
Jun 20 19:24:05 OpenWrt kern.warn kernel: [    0.780000] mtd: partition "rootfs" must either start or end on erase block boundary or be smaller than an erase block -- forcing read-only
Jun 20 19:24:05 OpenWrt kern.notice kernel: [    0.790000] mtd: partition "rootfs" set to be root filesystem
Jun 20 19:24:05 OpenWrt kern.info kernel: [    0.800000] mtd: partition "rootfs_data" created automatically, ofs=330000, len=C0000 
Jun 20 19:24:05 OpenWrt kern.notice kernel: [    0.810000] 0x000000330000-0x0000003f0000 : "rootfs_data"
Jun 20 19:24:05 OpenWrt kern.notice kernel: [    0.820000] 0x0000003f0000-0x000000400000 : "art"
Jun 20 19:24:05 OpenWrt kern.notice kernel: [    0.820000] 0x000000020000-0x0000003f0000 : "firmware"
Jun 20 19:24:05 OpenWrt kern.info kernel: [    1.070000] ag71xx_mdio: probed
Jun 20 19:24:05 OpenWrt kern.info kernel: [    1.070000] eth0: Atheros AG71xx at 0xba000000, irq 5
Jun 20 19:24:05 OpenWrt kern.info kernel: [    1.670000] eth0: Found an AR7240/AR9330 built-in switch
Jun 20 19:24:05 OpenWrt kern.info kernel: [   14.670000] hub 1-0:1.0: 1 port detected
Jun 20 19:24:05 OpenWrt kern.info kernel: [   14.690000] nf_conntrack version 0.5.0 (460 buckets, 1840 max)
Jun 20 19:24:05 OpenWrt kern.info kernel: [   15.170000] usb 1-1: new high-speed USB device number 2 using ehci-platform
Jun 20 19:24:05 OpenWrt kern.info kernel: [   15.230000] xt_time: kernel timezone is -0000
Jun 20 19:24:05 OpenWrt kern.info kernel: [   15.610000] usbcore: registered new interface driver cdc_acm
Jun 20 19:24:05 OpenWrt kern.info kernel: [   15.620000] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
Jun 20 19:24:05 OpenWrt kern.info kernel: [   15.740000] usbcore: registered new interface driver usbserial
Jun 20 19:24:05 OpenWrt kern.info kernel: [   15.750000] USB Serial support registered for generic
Jun 20 19:24:05 OpenWrt kern.info kernel: [   15.750000] usbcore: registered new interface driver usbserial_generic
Jun 20 19:24:05 OpenWrt kern.info kernel: [   15.760000] usbserial: USB Serial Driver core
Jun 20 19:24:05 OpenWrt kern.info kernel: [   15.850000] USB Serial support registered for GSM modem (1-port)
Jun 20 19:24:05 OpenWrt kern.info kernel: [   15.860000] usbcore: registered new interface driver option
Jun 20 19:24:05 OpenWrt kern.info kernel: [   15.870000] option: v0.7.2:USB Driver for GSM modems
Jun 20 19:24:07 OpenWrt user.notice usb-modeswitch: 1-0:1.0: Manufacturer=Linux_3.3.8_ehci_hcd Product=Generic_Platform_EHCI_Controller Serial=ehci-platform
Jun 20 19:24:08 OpenWrt user.notice usb-modeswitch: 1-1:1.0: Manufacturer=Huawei_Technologies Product=HUAWEI_Mobile Serial=?
Jun 20 19:24:08 OpenWrt user.notice usb-modeswitch: 1-1:1.0: Selecting /etc/usb_modeswitch.d/12d1:1446 for mode switching
Jun 20 19:24:08 OpenWrt user.notice usb-modeswitch: switching seemingly failed
Jun 20 19:24:08 OpenWrt user.notice usb-modeswitch: switching seemingly failed
Jun 20 19:24:08 OpenWrt user.notice usb-modeswitch: switching seemingly failed
Jun 20 19:24:08 OpenWrt user.notice usb-modeswitch: switching seemingly failed
Jun 20 19:24:08 OpenWrt user.notice usb-modeswitch: switching seemingly failed
Jun 20 19:24:08 OpenWrt user.notice usb-modeswitch: switching seemingly failed
Jun 20 19:24:08 OpenWrt user.notice usb-modeswitch: switching seemingly failed
Jun 20 19:24:08 OpenWrt user.notice usb-modeswitch: 1-1:1.1: Manufacturer=Huawei_Technologies Product=HUAWEI_Mobile Serial=?
Jun 20 19:24:08 OpenWrt user.notice usb-modeswitch: 1-1:1.1: Selecting /etc/usb_modeswitch.d/12d1:1446 for mode switching
Jun 20 19:24:08 OpenWrt user.notice usb-modeswitch: switching seemingly failed
Jun 20 19:24:08 OpenWrt user.notice usb-modeswitch: switching seemingly failed
Jun 20 19:24:08 OpenWrt user.notice usb-modeswitch: switching seemingly failed
Jun 20 19:24:08 OpenWrt user.notice usb-modeswitch: switching seemingly failed
Jun 20 19:24:08 OpenWrt user.notice usb-modeswitch: switching seemingly failed
Jun 20 19:24:08 OpenWrt user.notice usb-modeswitch: switching seemingly failed
Jun 20 19:24:08 OpenWrt user.notice usb-modeswitch: switching seemingly failed
Jun 20 19:24:09 OpenWrt daemon.notice netifd: Interface 'lan' is now up
Jun 20 19:24:09 OpenWrt kern.info kernel: [   21.000000] device eth0 entered promiscuous mode
Jun 20 19:24:09 OpenWrt daemon.notice netifd: Interface 'loopback' is now up
Jun 20 19:24:09 OpenWrt daemon.notice netifd: Interface 'wan' is now down
Jun 20 19:24:09 OpenWrt kern.info kernel: [   21.700000] eth0: link up (1000Mbps/Full duplex)
Jun 20 19:24:09 OpenWrt kern.info kernel: [   21.700000] br-lan: port 1(eth0) entered forwarding state
Jun 20 19:24:09 OpenWrt kern.info kernel: [   21.710000] br-lan: port 1(eth0) entered forwarding state
Jun 20 19:24:09 OpenWrt user.notice ifup: Enabling Router Solicitations on lan (br-lan)
Jun 20 19:24:11 OpenWrt kern.info kernel: [   23.710000] br-lan: port 1(eth0) entered forwarding state
Jun 20 19:24:11 OpenWrt kern.info kernel: [   23.710000] cfg80211: Calling CRDA for country: IT
Jun 20 19:24:11 OpenWrt kern.info kernel: [   23.720000] cfg80211: Regulatory domain changed to country: IT
Jun 20 19:24:11 OpenWrt kern.info kernel: [   23.720000] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
Jun 20 19:24:11 OpenWrt kern.info kernel: [   23.730000] cfg80211:   (2402000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm)
Jun 20 19:24:11 OpenWrt kern.info kernel: [   23.740000] cfg80211:   (5170000 KHz - 5250000 KHz @ 40000 KHz), (N/A, 2000 mBm)
Jun 20 19:24:11 OpenWrt kern.info kernel: [   23.750000] cfg80211:   (5250000 KHz - 5330000 KHz @ 40000 KHz), (N/A, 2000 mBm)
Jun 20 19:24:11 OpenWrt kern.info kernel: [   23.750000] cfg80211:   (5490000 KHz - 5710000 KHz @ 40000 KHz), (N/A, 2700 mBm)
Jun 20 19:24:12 OpenWrt user.notice upnp daemon: external interface not found, not starting
Jun 20 19:24:12 OpenWrt user.notice ifup: Enabling Router Solicitations on loopback (lo)
Jun 20 19:24:13 OpenWrt kern.info kernel: [   25.350000] device wlan0 entered promiscuous mode
Jun 20 19:24:15 OpenWrt kern.info kernel: [   26.920000] br-lan: port 2(wlan0) entered forwarding state
Jun 20 19:24:15 OpenWrt kern.info kernel: [   26.930000] br-lan: port 2(wlan0) entered forwarding state
Jun 20 19:24:17 OpenWrt kern.info kernel: [   28.930000] br-lan: port 2(wlan0) entered forwarding state
Jun 20 19:24:18 OpenWrt user.info sysinit: Loading defaults
Jun 20 19:24:18 OpenWrt user.info sysinit: Loading synflood protection
Jun 20 19:24:18 OpenWrt user.info sysinit: Adding custom chains
Jun 20 19:24:18 OpenWrt user.info sysinit: Loading zones
Jun 20 19:24:19 OpenWrt user.info sysinit: Loading forwardings
Jun 20 19:24:19 OpenWrt user.info sysinit: Loading rules
Jun 20 19:24:19 OpenWrt user.info sysinit: Loading redirects
Jun 20 19:24:19 OpenWrt user.info sysinit: Loading includes
Jun 20 19:24:19 OpenWrt user.info sysinit: Optimizing conntrack
Jun 20 19:24:19 OpenWrt user.info sysinit: Loading interfaces
Jun 20 19:24:19 OpenWrt user.info firewall: adding lan (br-lan) to zone lan
Jun 20 19:24:21 OpenWrt authpriv.info dropbear[1264]: Running in background
Jun 20 19:24:23 OpenWrt user.notice dnsmasq: DNS rebinding protection is active, will discard upstream RFC1918 responses!
Jun 20 19:24:23 OpenWrt user.notice dnsmasq: Allowing 127.0.0.0/8 responses
Jun 20 19:24:27 OpenWrt daemon.info dnsmasq[1403]: started, version 2.59 cachesize 150
Jun 20 19:24:27 OpenWrt daemon.info dnsmasq[1403]: compile time options: IPv6 GNU-getopt no-DBus no-i18n DHCP TFTP no-conntrack no-IDN
Jun 20 19:24:27 OpenWrt daemon.info dnsmasq-dhcp[1403]: DHCP, IP range 192.168.1.10 -- 192.168.1.59, lease time 1d12h
Jun 20 19:24:27 OpenWrt daemon.info dnsmasq[1403]: using local addresses only for domain lan
Jun 20 19:24:27 OpenWrt daemon.warn dnsmasq[1403]: no servers found in /tmp/resolv.conf.auto, will retry
Jun 20 19:24:27 OpenWrt daemon.info dnsmasq[1403]: read /etc/hosts - 1 addresses
Jun 20 19:24:27 OpenWrt daemon.info dnsmasq-dhcp[1403]: read /etc/ethers - 0 addresses
Jun 20 19:24:27 OpenWrt user.info sysinit: setting up led USB

If I unplug and plug the 3g dongle after boot 3G connection works

Jun 20 19:27:36 OpenWrt kern.info kernel: [  227.900000] usb 1-1: USB disconnect, device number 2
Jun 20 19:27:40 OpenWrt kern.info kernel: [  232.450000] usb 1-1: new high-speed USB device number 3 using ehci-platform
Jun 20 19:27:40 OpenWrt user.notice usb-modeswitch: 1-1:1.0: Manufacturer=Huawei_Technologies Product=HUAWEI_Mobile Serial=?
Jun 20 19:27:40 OpenWrt user.notice usb-modeswitch: 1-1:1.0: Selecting /etc/usb_modeswitch.d/12d1:1446 for mode switching
Jun 20 19:27:40 OpenWrt syslog.notice usb_modeswitch: switching device 12d1:1446 on 001/003
Jun 20 19:27:40 OpenWrt kern.info kernel: [  232.860000] usb 1-1: USB disconnect, device number 3
Jun 20 19:27:44 OpenWrt kern.info kernel: [  236.870000] usb 1-1: new high-speed USB device number 4 using ehci-platform
Jun 20 19:27:45 OpenWrt kern.info kernel: [  237.020000] option 1-1:1.0: GSM modem (1-port) converter detected
Jun 20 19:27:45 OpenWrt kern.info kernel: [  237.030000] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB0
Jun 20 19:27:45 OpenWrt kern.info kernel: [  237.040000] option 1-1:1.1: GSM modem (1-port) converter detected
Jun 20 19:27:45 OpenWrt kern.info kernel: [  237.040000] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB1
Jun 20 19:27:45 OpenWrt kern.info kernel: [  237.050000] option 1-1:1.2: GSM modem (1-port) converter detected
Jun 20 19:27:45 OpenWrt kern.info kernel: [  237.060000] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB2
Jun 20 19:27:46 OpenWrt syslog.notice usb_modeswitch: switched to 12d1:1506 on 001/003
Jun 20 19:27:46 OpenWrt user.notice usb-modeswitch: 1-1:1.1: Manufacturer=Huawei_Technologies Product=HUAWEI_Mobile Serial=?
Jun 20 19:27:46 OpenWrt user.notice usb-modeswitch: 1-1:1.0: Manufacturer=Huawei_Technologies Product=HUAWEI_Mobile Serial=?
Jun 20 19:27:47 OpenWrt user.notice usb-modeswitch: 1-1:1.1: Manufacturer=Huawei_Technologies Product=HUAWEI_Mobile Serial=?
Jun 20 19:27:47 OpenWrt user.notice usb-modeswitch: 1-1:1.2: Manufacturer=Huawei_Technologies Product=HUAWEI_Mobile Serial=?
Jun 20 19:27:48 OpenWrt user.notice usb-modeswitch: 1-1:1.3: Manufacturer=Huawei_Technologies Product=HUAWEI_Mobile Serial=?
Jun 20 19:27:48 OpenWrt user.notice usb-modeswitch: 1-1:1.4: Manufacturer=Huawei_Technologies Product=HUAWEI_Mobile Serial=?
Jun 20 19:27:49 OpenWrt daemon.notice pppd[1619]: pppd 2.4.5 started by root, uid 0
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: abort on (BUSY)
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: abort on (NO CARRIER)
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: abort on (ERROR)
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: report (CONNECT)
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: timeout set to 10 seconds
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: send (AT&F^M)
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: expect (OK)
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: AT&F^M^M
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: OK
Jun 20 19:27:50 OpenWrt local2.info chat[1623]:  -- got it
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: send (ATE1^M)
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: expect (OK)
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: ^M
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: ATE1^M^M
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: OK
Jun 20 19:27:50 OpenWrt local2.info chat[1623]:  -- got it
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: send (AT+CGDCONT=1,"IP","datacard.tre.it"^M)
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: timeout set to 30 seconds
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: expect (OK)
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: ^M
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: AT+CGDCONT=1,"IP","datacard.tre.it"^M^M
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: OK
Jun 20 19:27:50 OpenWrt local2.info chat[1623]:  -- got it
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: send (ATD*99***1#^M)
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: expect (CONNECT)
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: ^M
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: ATD*99***1#^M^M
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: CONNECT
Jun 20 19:27:50 OpenWrt local2.info chat[1623]:  -- got it
Jun 20 19:27:50 OpenWrt local2.info chat[1623]: send ( ^M)
Jun 20 19:27:50 OpenWrt daemon.info pppd[1619]: Serial connection established.
Jun 20 19:27:50 OpenWrt daemon.info pppd[1619]: Using interface 3g-wan
Jun 20 19:27:50 OpenWrt daemon.notice pppd[1619]: Connect: 3g-wan <--> /dev/ttyUSB0
Jun 20 19:27:54 OpenWrt daemon.warn pppd[1619]: Could not determine remote IP address: defaulting to 10.64.64.64
Jun 20 19:27:54 OpenWrt daemon.notice pppd[1619]: local  IP address 10.88.104.84
Jun 20 19:27:54 OpenWrt daemon.notice pppd[1619]: remote IP address 10.64.64.64
Jun 20 19:27:54 OpenWrt daemon.notice pppd[1619]: primary   DNS address 62.13.173.92
Jun 20 19:27:54 OpenWrt daemon.notice pppd[1619]: secondary DNS address 62.13.173.93
Jun 20 19:27:54 OpenWrt daemon.notice netifd: Interface 'wan' is now up
Jun 20 19:27:55 OpenWrt user.notice ifup: Enabling Router Solicitations on wan (3g-wan)
Jun 20 19:27:56 OpenWrt user.info firewall: adding wan (3g-wan) to zone wan
Jun 20 19:27:58 OpenWrt daemon.info dnsmasq[1403]: reading /tmp/resolv.conf.auto
Jun 20 19:27:58 OpenWrt daemon.info dnsmasq[1403]: using nameserver 62.13.173.92#53
Jun 20 19:27:58 OpenWrt daemon.info dnsmasq[1403]: using nameserver 62.13.173.93#53
Jun 20 19:27:58 OpenWrt daemon.info dnsmasq[1403]: using local addresses only for domain lan
Jun 20 19:27:58 OpenWrt user.info syslog: SNet version started
Jun 20 19:27:58 OpenWrt daemon.notice miniupnpd[1920]: HTTP listening on port 5000
Jun 20 19:27:58 OpenWrt daemon.notice miniupnpd[1920]: Listening for NAT-PMP traffic on port 5351
Jun 20 19:27:58 OpenWrt user.notice miniupnpd: adding firewall rules for 3g-wan to zone wan
Jun 20 19:28:02 OpenWrt daemon.info dnsmasq-dhcp[1403]: DHCPINFORM(br-lan) 192.168.1.136 00:26:18:49:ff:0c 
Jun 20 19:28:02 OpenWrt daemon.info dnsmasq-dhcp[1403]: DHCPACK(br-lan) 192.168.1.136 00:26:18:49:ff:0c Massy-PC
Jun 20 19:37:30 OpenWrt daemon.info pppd[1619]: System time change detected.

comment:17 follow-up: Changed 6 years ago by Massy

Incredible... seems that the problem is only with mr3420 because with a 1043ND (same build version) all is ok!

comment:18 in reply to: ↑ 17 Changed 6 years ago by HiQ

Same problem is on DIR-320

comment:19 Changed 6 years ago by raver@…

I've been having the same issue with the following hardware:

  • WNDR3700v2 + Huawei E173s
  • WL500gPv1 + Vodafone K5005

Here's what happened after power off/on.

Jun 21 03:32:07 Netgear user.notice usb-modeswitch: 1-1.7:1.0: Manufacturer=HUAWEI Product=HUAWEI_Mobile Serial=?
Jun 21 03:32:07 Netgear user.notice usb-modeswitch: 1-1.7:1.0: Selecting /etc/usb_modeswitch.d/12d1:1c0b for mode switching
Jun 21 03:32:07 Netgear user.notice usb-modeswitch: switching seemingly failed
Jun 21 03:32:07 Netgear user.notice usb-modeswitch: switching seemingly failed
Jun 21 03:32:07 Netgear user.notice usb-modeswitch: switching seemingly failed
Jun 21 03:32:07 Netgear user.notice usb-modeswitch: switching seemingly failed
Jun 21 03:32:07 Netgear user.notice usb-modeswitch: switching seemingly failed
Jun 21 03:32:08 Netgear user.notice usb-modeswitch: switching seemingly failed
Jun 21 03:32:08 Netgear user.notice usb-modeswitch: switching seemingly failed
Jun 21 03:32:08 Netgear user.notice usb-modeswitch: 1-1.7:1.1: Manufacturer=HUAWEI Product=HUAWEI_Mobile Serial=?
Jun 21 03:32:08 Netgear user.notice usb-modeswitch: 1-1.7:1.1: Selecting /etc/usb_modeswitch.d/12d1:1c0b for mode switching
Jun 21 03:32:08 Netgear user.notice usb-modeswitch: switching seemingly failed
Jun 21 03:32:08 Netgear user.notice usb-modeswitch: switching seemingly failed
Jun 21 03:32:08 Netgear user.notice usb-modeswitch: switching seemingly failed
Jun 21 03:32:08 Netgear user.notice usb-modeswitch: switching seemingly failed
Jun 21 03:32:08 Netgear user.notice usb-modeswitch: switching seemingly failed
Jun 21 03:32:08 Netgear user.notice usb-modeswitch: switching seemingly failed
Jun 21 03:32:08 Netgear user.notice usb-modeswitch: switching seemingly failed

usb_modewitch is called by hotplug but the device doesn't switch to modem mode. However the device switches mode if I manually run usb_modeswitch without unplugging it.

root@Netgear:~# usb_modeswitch -v 12d1 -p 1c0b -c /etc/usb_modeswitch.d/12d1:1c0b

Looking for target devices ...
 No devices in target mode or class found
Looking for default devices ...
   found matching product ID
   adding device
 Found device in default mode, class or configuration (1)
Accessing device 007 on bus 001 ...
Getting the current device configuration ...
 OK, got current device configuration (1)
Using first interface: 0x00
Using endpoints 0x0f (out) and 0x8f (in)
Inquiring device details; driver will be detached ...
Looking for active driver ...
 OK, driver found ("usb-storage")
 OK, driver "usb-storage" detached

SCSI inquiry data (for identification)
-------------------------
  Vendor String: HUAWEI  
   Model String: Mass Storage    
Revision String: 2.31
-------------------------

USB description data (for identification)
-------------------------
Manufacturer: HUAWEI
     Product: HUAWEI Mobile
  Serial No.: not provided
-------------------------
Setting up communication with interface 0
Using endpoint 0x0f for message sending ...
Trying to send message 1 to endpoint 0x0f ...
 OK, message successfully sent
Resetting response endpoint 0x8f
 Could not reset endpoint (probably harmless): -71
Resetting message endpoint 0x0f
 Could not reset endpoint (probably harmless): -19
 Device is gone, skipping any further commands
-> Run lsusb to note any changes. Bye.

comment:20 follow-up: Changed 6 years ago by jow

  • Resolution set to invalid
  • Status changed from reopened to closed

The ticket was reopened due to a modeswitch problem, it is not related to general autostart problems. Please refer to #11725.

comment:21 in reply to: ↑ 20 Changed 6 years ago by raver@…

Replying to jow:

The ticket was reopened due to a modeswitch problem, it is not related to general autostart problems. Please refer to #11725.

Sorry for the trouble. I had both #9211 and #11275 pages opened and because some of their content is identical I posted on #9211 by mistake ;)

comment:22 follow-up: Changed 6 years ago by Massy

  • Resolution invalid deleted
  • Status changed from closed to reopened

I think that isn't a usb_modeswitch problem, it happens also on my mr3420.
Please see the log:

root@OpenWrt:~# dmesg
[    0.000000] Linux version 3.3.8 (massy@massy-linux) (gcc version 4.6.3 20120201 (prerelease) (Linaro GCC 4.6-2012.02) ) #1 Mon Jun 25 20:44:09 CEST 2012
[    0.000000] MyLoader: sysp=f0f0f0f0, boardp=f0f0f0f0, parts=f0f0f0f0
[    0.000000] bootconsole [early0] enabled
[    0.000000] CPU revision is: 00019374 (MIPS 24Kc)
[    0.000000] SoC: Atheros AR7241 rev 1
[    0.000000] Clocks: CPU:400.000MHz, DDR:400.000MHz, AHB:200.000MHz, Ref:5.000MHz
[    0.000000] Determined physical RAM map:
[    0.000000]  memory: 02000000 @ 00000000 (usable)
[    0.000000] Initrd not found or empty - disabling initrd
[    0.000000] Zone PFN ranges:
[    0.000000]   Normal   0x00000000 -> 0x00002000
[    0.000000] Movable zone start PFN for each node
[    0.000000] Early memory PFN ranges
[    0.000000]     0: 0x00000000 -> 0x00002000
[    0.000000] On node 0 totalpages: 8192
[    0.000000] free_area_init_node: node 0, pgdat 802cd520, node_mem_map 81000000
[    0.000000]   Normal zone: 64 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 8128 pages, LIFO batch:0
[    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
[    0.000000] pcpu-alloc: [0] 0
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 8128
[    0.000000] Kernel command line:  board=TL-MR3420 console=ttyS0,115200 rootfstype=squashfs,jffs2 noinitrd
[    0.000000] PID hash table entries: 128 (order: -3, 512 bytes)
[    0.000000] Dentry cache hash table entries: 4096 (order: 2, 16384 bytes)
[    0.000000] Inode-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.000000] Primary instruction cache 64kB, VIPT, 4-way, linesize 32 bytes.
[    0.000000] Primary data cache 32kB, 4-way, VIPT, cache aliases, linesize 32 bytes
[    0.000000] Writing ErrCtl register=00000000
[    0.000000] Readback ErrCtl register=00000000
[    0.000000] Memory: 29288k/32768k available (2089k kernel code, 3480k reserved, 397k data, 200k init, 0k highmem)
[    0.000000] SLUB: Genslabs=9, HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.000000] NR_IRQS:48
[    0.000000] Calibrating delay loop... 265.42 BogoMIPS (lpj=1327104)
[    0.080000] pid_max: default: 32768 minimum: 301
[    0.080000] Mount-cache hash table entries: 512
[    0.090000] NET: Registered protocol family 16
[    0.090000] gpiochip_add: registered GPIOs 0 to 17 on device: ath79
[    0.100000] MIPS: machine is TP-LINK TL-MR3420
[    0.500000] registering PCI controller with io_map_base unset
[    0.540000] bio: create slab <bio-0> at 0
[    0.550000] PCI host bridge to bus 0000:00
[    0.550000] pci_bus 0000:00: root bus resource [mem 0x10000000-0x17ffffff]
[    0.560000] pci_bus 0000:00: root bus resource [io  0x0000]
[    0.560000] pci 0000:00:00.0: [168c:002e] type 0 class 0x000280
[    0.560000] pci 0000:00:00.0: fixup device configuration
[    0.570000] pci 0000:00:00.0: reg 10: [mem 0x10000000-0x1000ffff 64bit]
[    0.570000] pci 0000:00:00.0: supports D1
[    0.570000] pci 0000:00:00.0: PME# supported from D0 D1 D3hot
[    0.570000] pci 0000:00:00.0: BAR 0: assigned [mem 0x10000000-0x1000ffff 64bit]
[    0.570000] pci 0000:00:00.0: using irq 40 for pin 1
[    0.580000] Switching to clocksource MIPS
[    0.580000] NET: Registered protocol family 2
[    0.590000] IP route cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.590000] TCP established hash table entries: 1024 (order: 1, 8192 bytes)
[    0.600000] TCP bind hash table entries: 1024 (order: 0, 4096 bytes)
[    0.600000] TCP: Hash tables configured (established 1024 bind 1024)
[    0.610000] TCP reno registered
[    0.610000] UDP hash table entries: 256 (order: 0, 4096 bytes)
[    0.620000] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
[    0.630000] NET: Registered protocol family 1
[    0.630000] PCI: CLS 0 bytes, default 32
[    0.650000] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    0.650000] JFFS2 version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
[    0.660000] msgmni has been set to 57
[    0.670000] io scheduler noop registered
[    0.670000] io scheduler deadline registered (default)
[    0.680000] Serial: 8250/16550 driver, 1 ports, IRQ sharing disabled
[    0.710000] serial8250.0: ttyS0 at MMIO 0x18020000 (irq = 11) is a 16550A
[    0.710000] console [ttyS0] enabled, bootconsole disabled
[    0.730000] m25p80 spi0.0: found s25sl032a, expected m25p80
[    0.730000] m25p80 spi0.0: s25sl032a (4096 Kbytes)
[    0.740000] 5 tp-link partitions found on MTD device spi0.0
[    0.740000] Creating 5 MTD partitions on "spi0.0":
[    0.750000] 0x000000000000-0x000000020000 : "u-boot"
[    0.760000] 0x000000020000-0x0000000ffe00 : "kernel"
[    0.760000] mtd: partition "kernel" must either start or end on erase block boundary or be smaller than an erase block -- forcing read-only
[    0.770000] 0x0000000ffe00-0x0000003f0000 : "rootfs"
[    0.780000] mtd: partition "rootfs" must either start or end on erase block boundary or be smaller than an erase block -- forcing read-only
[    0.790000] mtd: partition "rootfs" set to be root filesystem
[    0.800000] mtd: partition "rootfs_data" created automatically, ofs=310000, len=E0000
[    0.810000] 0x000000310000-0x0000003f0000 : "rootfs_data"
[    0.820000] 0x0000003f0000-0x000000400000 : "art"
[    0.820000] 0x000000020000-0x0000003f0000 : "firmware"
[    1.070000] ag71xx_mdio: probed
[    1.070000] eth0: Atheros AG71xx at 0xba000000, irq 5
[    1.670000] eth0: Found an AR7240/AR9330 built-in switch
[    2.900000] eth1: Atheros AG71xx at 0xb9000000, irq 4
[    3.510000] ag71xx ag71xx.0: eth1: connected to PHY at ag71xx-mdio.1:04 [uid=004dd041, driver=Generic PHY]
[    3.520000] TCP westwood registered
[    3.520000] NET: Registered protocol family 17
[    3.520000] 8021q: 802.1Q VLAN Support v1.8
[    3.540000] VFS: Mounted root (squashfs filesystem) readonly on device 31:2.
[    3.540000] Freeing unused kernel memory: 200k freed
[    6.910000] Registered led device: tp-link:green:system
[    6.910000] Registered led device: tp-link:green:qss
[    6.910000] Registered led device: tp-link:green:3g
[    7.640000] eth0: link up (1000Mbps/Full duplex)
[   10.210000] JFFS2 notice: (405) jffs2_build_xattr_subsystem: complete building xattr subsystem, 1 of xdatum (0 unchecked, 0 orphan) and 13 of xref (0 dead, 2 orphan) found.
[   10.420000] eth0: link down
[   12.450000] Compat-wireless backport release: compat-wireless-2012-06-14
[   12.450000] Backport based on wireless-testing.git master-2012-06-14
[   12.460000] compat.git: wireless-testing.git
[   12.500000] cfg80211: Calling CRDA to update world regulatory domain
[   12.500000] cfg80211: World regulatory domain updated:
[   12.510000] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
[   12.520000] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[   12.520000] cfg80211:   (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[   12.530000] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[   12.540000] cfg80211:   (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[   12.550000] cfg80211:   (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[   13.030000] usbcore: registered new interface driver usbfs
[   13.040000] usbcore: registered new interface driver hub
[   13.050000] usbcore: registered new device driver usb
[   13.690000] PCI: Enabling device 0000:00:00.0 (0000 -> 0002)
[   13.700000] ath: EEPROM regdomain: 0x0
[   13.700000] ath: EEPROM indicates default country code should be used
[   13.700000] ath: doing EEPROM country->regdmn map search
[   13.700000] ath: country maps to regdmn code: 0x3a
[   13.700000] ath: Country alpha2 being used: US
[   13.700000] ath: Regpair used: 0x3a
[   13.710000] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
[   13.710000] Registered led device: ath9k-phy0
[   13.710000] ieee80211 phy0: Atheros AR9287 Rev:2 mem=0xb0000000, irq=40
[   13.720000] cfg80211: Calling CRDA for country: US
[   13.720000] cfg80211: Regulatory domain changed to country: US
[   13.730000] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
[   13.740000] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2700 mBm)
[   13.750000] cfg80211:   (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 1700 mBm)
[   13.750000] cfg80211:   (5250000 KHz - 5330000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[   13.760000] cfg80211:   (5490000 KHz - 5600000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[   13.770000] cfg80211:   (5650000 KHz - 5710000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[   13.780000] cfg80211:   (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 3000 mBm)
[   13.930000] PPP generic driver version 2.4.2
[   14.290000] ip_tables: (C) 2000-2006 Netfilter Core Team
[   14.500000] NET: Registered protocol family 24
[   14.620000] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[   14.630000] ehci-platform ehci-platform: Generic Platform EHCI Controller
[   14.640000] ehci-platform ehci-platform: new USB bus registered, assigned bus number 1
[   14.670000] ehci-platform ehci-platform: irq 3, io mem 0x1b000000
[   14.690000] ehci-platform ehci-platform: USB 2.0 started, EHCI 1.00
[   14.690000] hub 1-0:1.0: USB hub found
[   14.700000] hub 1-0:1.0: 1 port detected
[   14.720000] nf_conntrack version 0.5.0 (460 buckets, 1840 max)
[   15.200000] usb 1-1: new high-speed USB device number 2 using ehci-platform
[   15.260000] xt_time: kernel timezone is -0000
[   15.550000] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[   15.570000] uhci_hcd: USB Universal Host Controller Interface driver
[   15.770000] usbcore: registered new interface driver cdc_acm
[   15.780000] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
[   15.900000] usbcore: registered new interface driver usbserial
[   15.910000] USB Serial support registered for generic
[   15.910000] usbcore: registered new interface driver usbserial_generic
[   15.920000] usbserial: USB Serial Driver core
[   16.040000] USB Serial support registered for GSM modem (1-port)
[   16.040000] usbcore: registered new interface driver option
[   16.050000] option: v0.7.2:USB Driver for GSM modems
[   21.340000] device eth0 entered promiscuous mode
[   22.170000] eth0: link up (1000Mbps/Full duplex)
[   22.170000] br-lan: port 1(eth0) entered forwarding state
[   22.180000] br-lan: port 1(eth0) entered forwarding state
[   24.180000] br-lan: port 1(eth0) entered forwarding state
root@OpenWrt:~#

As you can see there isn't usb_modeswitch log but if a unplug and plug the dongle

Jun 25 19:27:30 OpenWrt kern.info kernel: [  161.890000] usb 1-1: USB disconnect, device number 2
Jun 25 19:27:35 OpenWrt kern.info kernel: [  167.770000] usb 1-1: new high-speed USB device number 3 using ehci-platform
Jun 25 19:27:36 OpenWrt user.notice usb-modeswitch: 1-1:1.0: Manufacturer=Vodafone_(ZTE) Product=Vodafone_Mobile_Broadband_K4505-z Serial=P680A2VDFD010000
Jun 25 19:27:36 OpenWrt user.notice usb-modeswitch: 1-1:1.0: Selecting /etc/usb_modeswitch.d/19d2:0101 for mode switching
Jun 25 19:27:36 OpenWrt syslog.notice usb_modeswitch: switching device 19d2:0101 on 001/003
Jun 25 19:27:38 OpenWrt kern.info kernel: [  170.480000] usb 1-1: USB disconnect, device number 3
Jun 25 19:27:43 OpenWrt kern.info kernel: [  175.260000] usb 1-1: new high-speed USB device number 4 using ehci-platform
Jun 25 19:27:43 OpenWrt kern.info kernel: [  175.410000] option 1-1:1.0: GSM modem (1-port) converter detected
Jun 25 19:27:43 OpenWrt syslog.notice usb_modeswitch: switched to 19d2:0104 on 001/003
Jun 25 19:27:43 OpenWrt kern.info kernel: [  175.420000] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB0
Jun 25 19:27:43 OpenWrt kern.info kernel: [  175.430000] option 1-1:1.1: GSM modem (1-port) converter detected
Jun 25 19:27:43 OpenWrt kern.info kernel: [  175.430000] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB1
Jun 25 19:27:43 OpenWrt kern.info kernel: [  175.440000] option 1-1:1.2: GSM modem (1-port) converter detected
Jun 25 19:27:43 OpenWrt kern.info kernel: [  175.450000] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB2
Jun 25 19:27:43 OpenWrt kern.info kernel: [  175.450000] option 1-1:1.3: GSM modem (1-port) converter detected
Jun 25 19:27:43 OpenWrt kern.info kernel: [  175.460000] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB3
Jun 25 19:27:44 OpenWrt user.notice usb-modeswitch: 1-1:1.0: Manufacturer=Vodafone_(ZTE) Product=Vodafone_Mobile_Broadband_K4505-z Serial=P680A2VDFD010000
Jun 25 19:27:44 OpenWrt user.notice usb-modeswitch: 1-1:1.1: Manufacturer=Vodafone_(ZTE) Product=Vodafone_Mobile_Broadband_K4505-z Serial=P680A2VDFD010000
Jun 25 19:27:44 OpenWrt user.notice usb-modeswitch: 1-1:1.2: Manufacturer=Vodafone_(ZTE) Product=Vodafone_Mobile_Broadband_K4505-z Serial=P680A2VDFD010000
Jun 25 19:27:44 OpenWrt user.notice usb-modeswitch: 1-1:1.3: Manufacturer=Vodafone_(ZTE) Product=Vodafone_Mobile_Broadband_K4505-z Serial=P680A2VDFD010000
Jun 25 19:27:45 OpenWrt user.notice usb-modeswitch: 1-1:1.4: Manufacturer=Vodafone_(ZTE) Product=Vodafone_Mobile_Broadband_K4505-z Serial=P680A2VDFD010000
Jun 25 19:27:45 OpenWrt user.notice usb-modeswitch: 1-1:1.5: Manufacturer=Vodafone_(ZTE) Product=Vodafone_Mobile_Broadband_K4505-z Serial=P680A2VDFD010000
Jun 25 19:27:46 OpenWrt daemon.notice pppd[1373]: pppd 2.4.5 started by root, uid 0
Jun 25 19:27:47 OpenWrt local2.info chat[1377]: abort on (BUSY)
Jun 25 19:27:47 OpenWrt local2.info chat[1377]: abort on (NO CARRIER)
Jun 25 19:27:47 OpenWrt local2.info chat[1377]: abort on (ERROR)
Jun 25 19:27:47 OpenWrt local2.info chat[1377]: report (CONNECT)
Jun 25 19:27:47 OpenWrt local2.info chat[1377]: timeout set to 10 seconds
Jun 25 19:27:47 OpenWrt local2.info chat[1377]: send (AT&F^M)
Jun 25 19:27:47 OpenWrt local2.info chat[1377]: expect (OK)
Jun 25 19:27:47 OpenWrt local2.info chat[1377]: AT&F^M^M
Jun 25 19:27:47 OpenWrt local2.info chat[1377]: OK

The problem is present in all versions and only on mr3420
Many thanks ;)

comment:23 Changed 6 years ago by jow

  • Milestone changed from Attitude Adjustment (trunk) to Bugs Paradise
  • Priority changed from response-needed to lowest

Seems to be hardware issue then, I don't think we'll ever find a solid solution for this. Feel free to investigate possible workarounds.

comment:24 in reply to: ↑ 22 Changed 6 years ago by Nilfred <nilfred@…>

Replying to Massy:

if a unplug and plug the dongle

root@TL-MR3220:~# cat /sys/kernel/debug/gpio
GPIOs 0-17, ath79:
 gpio-0   (tp-link:green:qss   ) out hi
 gpio-1   (tp-link:green:system) out hi
 gpio-6   (USB power           ) out hi
 gpio-8   (tp-link:green:3g    ) out hi
 gpio-11  (reset               ) in  hi
 gpio-12  (qss                 ) in  hi

IMMO You can simulate unplug and plug the dongle turning USB power off and then on.

comment:25 Changed 6 years ago by Massy

The problem is usb_modeswitch, I have done many test and the solution is to add
sleep 1 on 20-modeswitch

/etc/hotplug.d/usb/20-modeswitch

#!/bin/sh

sleep 1

local uVid uPid uMa uPr uSe
local sVe sMo sRe

local modeswitch="/usr/bin/usb_modeswitch"

log() {

logger -t "usb-modeswitch" "$@"

etc etc

comment:26 Changed 6 years ago by jow

I am not convinced by the solution. If the sleep would've been the problem, the above failure log would at least show

user.notice usb-modeswitch: 1-1:1.0: Manufacturer=? Product=? Serial=?"

comment:27 Changed 6 years ago by anonymous

You're right, i have tested now a e353 and doesn't work for the same problem.
So sleep 1 isn't the solution...

comment:28 Changed 6 years ago by anonymous

Fixed with r32602

comment:29 Changed 6 years ago by jow

  • Resolution set to fixed
  • Status changed from reopened to closed

comment:30 Changed 4 years ago by anonymous

  • Resolution fixed deleted
  • Status changed from closed to reopened

Maybe back at r40698?

comment:31 Changed 4 years ago by nbd

"Maybe"?

comment:32 Changed 4 years ago by anonymous

Sorry for the maybe. In detail my problem looks like this:
When I hard reboot my TP-Link WR842ND V2 with r40698 on it and a plugged in 3g dongle my log looks like this and the 3g connection is not working:

Mon May 26 16:01:57 2014 kern.warn kernel: [    0.000000] Early memory node ranges
Mon May 26 16:01:57 2014 kern.warn kernel: [    0.000000]   node   0: [mem 0x00000000-0x01ffffff]
Mon May 26 16:01:57 2014 kern.debug kernel: [    0.000000] On node 0 totalpages: 8192
Mon May 26 16:01:57 2014 kern.debug kernel: [    0.000000] free_area_init_node: node 0, pgdat 80334b60, node_mem_map 81000000
Mon May 26 16:01:57 2014 kern.debug kernel: [    0.000000]   Normal zone: 64 pages used for memmap
Mon May 26 16:01:57 2014 kern.debug kernel: [    0.000000]   Normal zone: 0 pages reserved
Mon May 26 16:01:57 2014 kern.debug kernel: [    0.000000]   Normal zone: 8192 pages, LIFO batch:0
Mon May 26 16:01:57 2014 kern.warn kernel: [    0.000000] Primary instruction cache 64kB, VIPT, 4-way, linesize 32 bytes.
Mon May 26 16:01:57 2014 kern.warn kernel: [    0.000000] Primary data cache 32kB, 4-way, VIPT, cache aliases, linesize 32 bytes
Mon May 26 16:01:57 2014 kern.debug kernel: [    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
Mon May 26 16:01:57 2014 kern.debug kernel: [    0.000000] pcpu-alloc: [0] 0 
Mon May 26 16:01:57 2014 kern.warn kernel: [    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 8128
Mon May 26 16:01:57 2014 kern.notice kernel: [    0.000000] Kernel command line:  board=TL-WR842N-v2 console=ttyS0,115200 rootfstype=squashfs,jffs2 noinitrd
Mon May 26 16:01:57 2014 kern.info kernel: [    0.000000] PID hash table entries: 128 (order: -3, 512 bytes)
Mon May 26 16:01:57 2014 kern.info kernel: [    0.000000] Dentry cache hash table entries: 4096 (order: 2, 16384 bytes)
Mon May 26 16:01:57 2014 kern.info kernel: [    0.000000] Inode-cache hash table entries: 2048 (order: 1, 8192 bytes)
Mon May 26 16:01:57 2014 kern.info kernel: [    0.000000] Writing ErrCtl register=00000000
Mon May 26 16:01:57 2014 kern.info kernel: [    0.000000] Readback ErrCtl register=00000000
Mon May 26 16:01:57 2014 kern.info kernel: [    0.000000] Memory: 28588k/32768k available (2371k kernel code, 4180k reserved, 618k data, 272k init, 0k highmem)
Mon May 26 16:01:57 2014 kern.info kernel: [    0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
Mon May 26 16:01:57 2014 kern.info kernel: [    0.000000] NR_IRQS:51
Mon May 26 16:01:57 2014 kern.info kernel: [    0.070000] Calibrating delay loop... 266.64 BogoMIPS (lpj=1333248)
Mon May 26 16:01:57 2014 kern.info kernel: [    0.080000] pid_max: default: 32768 minimum: 301
Mon May 26 16:01:57 2014 kern.info kernel: [    0.080000] Mount-cache hash table entries: 512
Mon May 26 16:01:57 2014 kern.info kernel: [    0.090000] NET: Registered protocol family 16
Mon May 26 16:01:57 2014 kern.info kernel: [    0.090000] MIPS: machine is TP-LINK TL-WR842N/ND v2
Mon May 26 16:01:57 2014 kern.info kernel: [    0.510000] bio: create slab <bio-0> at 0
Mon May 26 16:01:57 2014 kern.info kernel: [    0.520000] Switching to clocksource MIPS
Mon May 26 16:01:57 2014 kern.info kernel: [    0.530000] NET: Registered protocol family 2
Mon May 26 16:01:57 2014 kern.info kernel: [    0.530000] TCP established hash table entries: 512 (order: 0, 4096 bytes)
Mon May 26 16:01:57 2014 kern.info kernel: [    0.530000] TCP bind hash table entries: 512 (order: -1, 2048 bytes)
Mon May 26 16:01:57 2014 kern.info kernel: [    0.540000] TCP: Hash tables configured (established 512 bind 512)
Mon May 26 16:01:57 2014 kern.info kernel: [    0.540000] TCP: reno registered
Mon May 26 16:01:57 2014 kern.info kernel: [    0.550000] UDP hash table entries: 256 (order: 0, 4096 bytes)
Mon May 26 16:01:57 2014 kern.info kernel: [    0.550000] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
Mon May 26 16:01:57 2014 kern.info kernel: [    0.560000] NET: Registered protocol family 1
Mon May 26 16:01:57 2014 kern.debug kernel: [    0.560000] PCI: CLS 0 bytes, default 32
Mon May 26 16:01:57 2014 kern.info kernel: [    0.580000] squashfs: version 4.0 (2009/01/31) Phillip Lougher
Mon May 26 16:01:57 2014 kern.info kernel: [    0.580000] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
Mon May 26 16:01:57 2014 kern.info kernel: [    0.600000] msgmni has been set to 55
Mon May 26 16:01:57 2014 kern.info kernel: [    0.600000] io scheduler noop registered
Mon May 26 16:01:57 2014 kern.info kernel: [    0.600000] io scheduler deadline registered (default)
Mon May 26 16:01:57 2014 kern.info kernel: [    0.610000] Serial: 8250/16550 driver, 16 ports, IRQ sharing enabled
Mon May 26 16:01:57 2014 kern.info kernel: [    0.640000] serial8250.0: ttyS0 at MMIO 0x18020000 (irq = 11) is a 16550A
Mon May 26 16:01:57 2014 kern.info kernel: [    0.650000] console [ttyS0] enabled, bootconsole disabled
Mon May 26 16:01:57 2014 kern.info kernel: [    0.660000] ath79-spi ath79-spi: master is unqueued, this is deprecated
Mon May 26 16:01:57 2014 kern.warn kernel: [    0.670000] m25p80 spi0.0: found s25fl064k, expected m25p80
Mon May 26 16:01:57 2014 kern.info kernel: [    0.680000] m25p80 spi0.0: s25fl064k (8192 Kbytes)
Mon May 26 16:01:57 2014 kern.notice kernel: [    0.680000] 5 tp-link partitions found on MTD device spi0.0
Mon May 26 16:01:57 2014 kern.notice kernel: [    0.690000] Creating 5 MTD partitions on "spi0.0":
Mon May 26 16:01:57 2014 kern.notice kernel: [    0.690000] 0x000000000000-0x000000020000 : "u-boot"
Mon May 26 16:01:57 2014 kern.notice kernel: [    0.700000] 0x000000020000-0x00000012b108 : "kernel"
Mon May 26 16:01:57 2014 kern.warn kernel: [    0.700000] mtd: partition "kernel" must either start or end on erase block boundary or be smaller than an erase block -- forcing read-only
Mon May 26 16:01:57 2014 kern.notice kernel: [    0.720000] 0x00000012b108-0x0000007f0000 : "rootfs"
Mon May 26 16:01:57 2014 kern.warn kernel: [    0.720000] mtd: partition "rootfs" must either start or end on erase block boundary or be smaller than an erase block -- forcing read-only
Mon May 26 16:01:57 2014 kern.notice kernel: [    0.740000] mtd: device 2 (rootfs) set to be root filesystem
Mon May 26 16:01:57 2014 kern.notice kernel: [    0.740000] 1 squashfs-split partitions found on MTD device rootfs
Mon May 26 16:01:57 2014 kern.notice kernel: [    0.750000] 0x000000300000-0x0000007f0000 : "rootfs_data"
Mon May 26 16:01:57 2014 kern.notice kernel: [    0.760000] 0x0000007f0000-0x000000800000 : "art"
Mon May 26 16:01:57 2014 kern.notice kernel: [    0.760000] 0x000000020000-0x0000007f0000 : "firmware"
Mon May 26 16:01:57 2014 kern.info kernel: [    0.790000] libphy: ag71xx_mdio: probed
Mon May 26 16:01:57 2014 kern.info kernel: [    1.340000] ag71xx ag71xx.0: connected to PHY at ag71xx-mdio.1:00 [uid=004dd042, driver=Generic PHY]
Mon May 26 16:01:57 2014 kern.info kernel: [    1.350000] eth0: Atheros AG71xx at 0xb9000000, irq 4, mode:MII
Mon May 26 16:01:57 2014 kern.info kernel: [    1.910000] ag71xx-mdio.1: Found an AR934X built-in switch
Mon May 26 16:01:57 2014 kern.info kernel: [    2.950000] eth1: Atheros AG71xx at 0xba000000, irq 5, mode:GMII
Mon May 26 16:01:57 2014 kern.info kernel: [    2.960000] TCP: cubic registered
Mon May 26 16:01:57 2014 kern.info kernel: [    2.960000] NET: Registered protocol family 17
Mon May 26 16:01:57 2014 kern.notice kernel: [    2.970000] Bridge firewalling registered
Mon May 26 16:01:57 2014 kern.info kernel: [    2.970000] 8021q: 802.1Q VLAN Support v1.8
Mon May 26 16:01:57 2014 kern.info kernel: [    2.980000] VFS: Mounted root (squashfs filesystem) readonly on device 31:2.
Mon May 26 16:01:57 2014 kern.info kernel: [    2.990000] Freeing unused kernel memory: 272K (8034c000 - 80390000)
Mon May 26 16:01:57 2014 kern.info kernel: [    5.710000] usbcore: registered new interface driver usbfs
Mon May 26 16:01:57 2014 kern.info kernel: [    5.720000] usbcore: registered new interface driver hub
Mon May 26 16:01:57 2014 kern.info kernel: [    5.720000] usbcore: registered new device driver usb
Mon May 26 16:01:57 2014 kern.info kernel: [    5.740000] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
Mon May 26 16:01:57 2014 kern.info kernel: [    5.740000] ehci-platform: EHCI generic platform driver
Mon May 26 16:01:57 2014 kern.info kernel: [    5.750000] ehci-platform ehci-platform: EHCI Host Controller
Mon May 26 16:01:57 2014 kern.info kernel: [    5.760000] ehci-platform ehci-platform: new USB bus registered, assigned bus number 1
Mon May 26 16:01:57 2014 kern.info kernel: [    5.770000] ehci-platform ehci-platform: TX-TX IDP fix enabled
Mon May 26 16:01:57 2014 kern.info kernel: [    5.770000] ehci-platform ehci-platform: irq 3, io mem 0x1b000000
Mon May 26 16:01:57 2014 kern.info kernel: [    5.800000] ehci-platform ehci-platform: USB 2.0 started, EHCI 1.00
Mon May 26 16:01:57 2014 kern.info kernel: [    5.800000] hub 1-0:1.0: USB hub found
Mon May 26 16:01:57 2014 kern.info kernel: [    5.810000] hub 1-0:1.0: 1 port detected
Mon May 26 16:01:57 2014 kern.info kernel: [    5.810000] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
Mon May 26 16:01:57 2014 kern.info kernel: [    6.130000] usb 1-1: new high-speed USB device number 2 using ehci-platform
Mon May 26 16:01:57 2014 kern.notice kernel: [    9.180000] jffs2: notice: (343) jffs2_build_xattr_subsystem: complete building xattr subsystem, 2 of xdatum (1 unchecked, 1 orphan) and 26 of xref (0 dead, 14 orphan) found.
Mon May 26 16:01:57 2014 kern.info kernel: [   11.280000] NET: Registered protocol family 10
Mon May 26 16:01:57 2014 kern.info kernel: [   11.290000] tun: Universal TUN/TAP device driver, 1.6
Mon May 26 16:01:57 2014 kern.info kernel: [   11.300000] tun: (C) 1999-2004 Max Krasnyansky <maxk@qualcomm.com>
Mon May 26 16:01:57 2014 kern.info kernel: [   11.310000] nf_conntrack version 0.5.0 (450 buckets, 1800 max)
Mon May 26 16:01:57 2014 kern.info kernel: [   11.330000] ip6_tables: (C) 2000-2006 Netfilter Core Team
Mon May 26 16:01:57 2014 kern.info kernel: [   11.350000] uhci_hcd: USB Universal Host Controller Interface driver
Mon May 26 16:01:57 2014 kern.info kernel: [   11.360000] Loading modules backported from Linux version master-2014-05-22-0-gf2032ea
Mon May 26 16:01:57 2014 kern.info kernel: [   11.370000] Backport generated by backports.git backports-20140320-37-g5c33da0
Mon May 26 16:01:57 2014 kern.info kernel: [   11.380000] ip_tables: (C) 2000-2006 Netfilter Core Team
Mon May 26 16:01:57 2014 kern.info kernel: [   11.410000] usbcore: registered new interface driver usbserial
Mon May 26 16:01:57 2014 kern.info kernel: [   11.420000] usbcore: registered new interface driver usbserial_generic
Mon May 26 16:01:57 2014 kern.info kernel: [   11.430000] usbserial: USB Serial support registered for generic
Mon May 26 16:01:57 2014 kern.info kernel: [   11.450000] xt_time: kernel timezone is -0000
Mon May 26 16:01:57 2014 kern.info kernel: [   11.500000] cfg80211: Calling CRDA to update world regulatory domain
Mon May 26 16:01:57 2014 kern.info kernel: [   11.500000] cfg80211: World regulatory domain updated:
Mon May 26 16:01:57 2014 kern.info kernel: [   11.510000] cfg80211:  DFS Master region: unset
Mon May 26 16:01:57 2014 kern.info kernel: [   11.510000] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)
Mon May 26 16:01:57 2014 kern.info kernel: [   11.520000] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
Mon May 26 16:01:57 2014 kern.info kernel: [   11.530000] cfg80211:   (2457000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
Mon May 26 16:01:57 2014 kern.info kernel: [   11.540000] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (N/A, 2000 mBm), (N/A)
Mon May 26 16:01:57 2014 kern.info kernel: [   11.550000] cfg80211:   (5170000 KHz - 5250000 KHz @ 80000 KHz), (N/A, 2000 mBm), (N/A)
Mon May 26 16:01:57 2014 kern.info kernel: [   11.560000] cfg80211:   (5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 2000 mBm), (N/A)
Mon May 26 16:01:57 2014 kern.info kernel: [   11.570000] cfg80211:   (57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 0 mBm), (N/A)
Mon May 26 16:01:57 2014 kern.info kernel: [   11.640000] PPP generic driver version 2.4.2
Mon May 26 16:01:57 2014 kern.info kernel: [   11.640000] NET: Registered protocol family 24
Mon May 26 16:01:57 2014 kern.info kernel: [   11.680000] usbcore: registered new interface driver option
Mon May 26 16:01:57 2014 kern.info kernel: [   11.690000] usbserial: USB Serial support registered for GSM modem (1-port)
Mon May 26 16:01:57 2014 kern.debug kernel: [   11.720000] ath: EEPROM regdomain: 0x0
Mon May 26 16:01:57 2014 kern.debug kernel: [   11.720000] ath: EEPROM indicates default country code should be used
Mon May 26 16:01:57 2014 kern.debug kernel: [   11.720000] ath: doing EEPROM country->regdmn map search
Mon May 26 16:01:57 2014 kern.debug kernel: [   11.720000] ath: country maps to regdmn code: 0x3a
Mon May 26 16:01:57 2014 kern.debug kernel: [   11.720000] ath: Country alpha2 being used: US
Mon May 26 16:01:57 2014 kern.debug kernel: [   11.720000] ath: Regpair used: 0x3a
Mon May 26 16:01:57 2014 kern.debug kernel: [   11.730000] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
Mon May 26 16:01:57 2014 kern.info kernel: [   11.750000] ieee80211 phy0: Atheros AR9340 Rev:0 mem=0xb8100000, irq=47
Mon May 26 16:01:57 2014 kern.info kernel: [   11.760000] cfg80211: Calling CRDA for country: US
Mon May 26 16:01:57 2014 kern.info kernel: [   11.760000] cfg80211: Regulatory domain changed to country: US
Mon May 26 16:01:57 2014 kern.info kernel: [   11.770000] cfg80211:  DFS Master region: FCC
Mon May 26 16:01:57 2014 kern.info kernel: [   11.770000] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)
Mon May 26 16:01:57 2014 kern.info kernel: [   11.780000] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 3000 mBm), (N/A)
Mon May 26 16:01:57 2014 kern.info kernel: [   11.790000] cfg80211:   (5170000 KHz - 5250000 KHz @ 80000 KHz), (N/A, 1700 mBm), (N/A)
Mon May 26 16:01:57 2014 kern.info kernel: [   11.800000] cfg80211:   (5250000 KHz - 5330000 KHz @ 80000 KHz), (N/A, 2300 mBm), (0 s)
Mon May 26 16:01:57 2014 kern.info kernel: [   11.810000] cfg80211:   (5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 3000 mBm), (N/A)
Mon May 26 16:01:57 2014 kern.info kernel: [   11.820000] cfg80211:   (57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 4000 mBm), (N/A)
Mon May 26 16:01:58 2014 user.emerg syslog: Error: Failed to connect to ubus
Mon May 26 16:02:01 2014 authpriv.info dropbear[801]: Not backgrounding
Mon May 26 16:02:02 2014 user.emerg syslog: setting up led WAN
Mon May 26 16:02:02 2014 user.emerg syslog: setting up led LAN1
Mon May 26 16:02:02 2014 user.emerg syslog: setting up led LAN2
Mon May 26 16:02:02 2014 user.emerg syslog: setting up led LAN3
Mon May 26 16:02:02 2014 user.emerg syslog: setting up led LAN4
Mon May 26 16:02:02 2014 user.emerg syslog: setting up led WLAN
Mon May 26 16:02:02 2014 user.emerg syslog: setting up led USB
Mon May 26 16:02:03 2014 user.emerg syslog: - init complete -
Mon May 26 16:02:05 2014 kern.info kernel: [   21.040000] IPv6: ADDRCONF(NETDEV_UP): eth1: link is not ready
Mon May 26 16:02:05 2014 kern.info kernel: [   21.040000] device eth1 entered promiscuous mode
Mon May 26 16:02:05 2014 kern.info kernel: [   21.050000] IPv6: ADDRCONF(NETDEV_UP): br-lan: link is not ready
Mon May 26 16:02:05 2014 daemon.notice netifd: Interface 'lan' is enabled
Mon May 26 16:02:05 2014 daemon.notice netifd: Interface 'lan' is setting up now
Mon May 26 16:02:05 2014 daemon.notice netifd: Interface 'lan' is now up
Mon May 26 16:02:05 2014 daemon.notice netifd: Interface 'loopback' is enabled
Mon May 26 16:02:05 2014 daemon.notice netifd: Interface 'wan' is setting up now
Mon May 26 16:02:05 2014 daemon.warn odhcpd[763]: Failed to send to ff02::1%br-lan (Cannot assign requested address)
Mon May 26 16:02:05 2014 daemon.notice netifd: Network device 'lo' link is up
Mon May 26 16:02:05 2014 daemon.notice netifd: Interface 'loopback' has link connectivity 
Mon May 26 16:02:05 2014 daemon.notice netifd: Interface 'loopback' is setting up now
Mon May 26 16:02:05 2014 daemon.notice netifd: Interface 'loopback' is now up
Mon May 26 16:02:05 2014 daemon.warn odhcpd[763]: Failed to send to ff02::1%br-lan (Cannot assign requested address)
Mon May 26 16:02:05 2014 user.emerg syslog: 'radio0' is disabled
Mon May 26 16:02:05 2014 user.emerg syslog: 'radio0' is disabled
Mon May 26 16:02:05 2014 daemon.notice netifd: Interface 'wan' is now down
Mon May 26 16:02:05 2014 user.notice firewall: Reloading firewall due to ifup of lan (br-lan)
Mon May 26 16:02:09 2014 daemon.info dnsmasq[946]: started, version 2.71 cachesize 150
Mon May 26 16:02:09 2014 daemon.info dnsmasq[946]: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP no-DHCPv6 no-Lua TFTP no-conntrack no-ipset no-auth no-DNSSEC
Mon May 26 16:02:09 2014 daemon.info dnsmasq-dhcp[946]: DHCP, IP range 192.168.1.100 -- 192.168.1.249, lease time 12h
Mon May 26 16:02:09 2014 daemon.info dnsmasq[946]: using local addresses only for domain lan
Mon May 26 16:02:09 2014 daemon.warn dnsmasq[946]: no servers found in /tmp/resolv.conf.auto, will retry
Mon May 26 16:02:09 2014 daemon.info dnsmasq[946]: read /etc/hosts - 1 addresses
Mon May 26 16:02:09 2014 daemon.info dnsmasq-dhcp[946]: read /etc/ethers - 0 addresses
Mon May 26 16:03:22 2014 kern.info kernel: [   98.640000] eth1: link up (1000Mbps/Full duplex)
Mon May 26 16:03:22 2014 kern.info kernel: [   98.640000] br-lan: port 1(eth1) entered forwarding state
Mon May 26 16:03:22 2014 kern.info kernel: [   98.650000] br-lan: port 1(eth1) entered forwarding state
Mon May 26 16:03:22 2014 kern.info kernel: [   98.650000] IPv6: ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
Mon May 26 16:03:22 2014 daemon.notice netifd: Network device 'eth1' link is up
Mon May 26 16:03:22 2014 daemon.notice netifd: Bridge 'br-lan' link is up
Mon May 26 16:03:22 2014 daemon.notice netifd: Interface 'lan' has link connectivity 
Mon May 26 16:03:22 2014 kern.info kernel: [   98.660000] IPv6: ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready
Mon May 26 16:03:24 2014 kern.info kernel: [  100.650000] br-lan: port 1(eth1) entered forwarding state}}}
Then I unplug my 3g dongle and plug it in again my log looks like this and everything is working: 
{{{
Mon May 26 16:08:38 2014 kern.info kernel: [  414.620000] usb 1-1: USB disconnect, device number 2
Mon May 26 16:08:46 2014 kern.info kernel: [  422.470000] usb 1-1: new high-speed USB device number 3 using ehci-platform
Mon May 26 16:08:46 2014 kern.info kernel: [  423.000000] usb 1-1: USB disconnect, device number 3
Mon May 26 16:08:50 2014 kern.info kernel: [  426.920000] usb 1-1: new high-speed USB device number 4 using ehci-platform
Mon May 26 16:08:51 2014 kern.info kernel: [  427.080000] option 1-1:1.0: GSM modem (1-port) converter detected
Mon May 26 16:08:51 2014 kern.info kernel: [  427.090000] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB0
Mon May 26 16:08:51 2014 kern.info kernel: [  427.110000] option 1-1:1.3: GSM modem (1-port) converter detected
Mon May 26 16:08:51 2014 kern.info kernel: [  427.120000] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB1
Mon May 26 16:08:51 2014 kern.info kernel: [  427.120000] option 1-1:1.4: GSM modem (1-port) converter detected
Mon May 26 16:08:51 2014 kern.info kernel: [  427.140000] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB2
Mon May 26 16:08:51 2014 daemon.notice netifd: Interface 'wan' is setting up now
Mon May 26 16:08:53 2014 daemon.notice netifd: wan (1165): Trying to set mode
Mon May 26 16:08:54 2014 daemon.notice pppd[1262]: pppd 2.4.5 started by root, uid 0
Mon May 26 16:08:55 2014 local2.info chat[1265]: abort on (BUSY)
Mon May 26 16:08:55 2014 local2.info chat[1265]: abort on (NO CARRIER)
Mon May 26 16:08:55 2014 local2.info chat[1265]: abort on (ERROR)
Mon May 26 16:08:55 2014 local2.info chat[1265]: report (CONNECT)
Mon May 26 16:08:55 2014 local2.info chat[1265]: timeout set to 10 seconds
Mon May 26 16:08:55 2014 local2.info chat[1265]: send (AT&F^M)
Mon May 26 16:08:55 2014 local2.info chat[1265]: expect (OK)
Mon May 26 16:08:55 2014 local2.info chat[1265]: AT&F^M^M
Mon May 26 16:08:55 2014 local2.info chat[1265]: OK
Mon May 26 16:08:55 2014 local2.info chat[1265]:  -- got it
Mon May 26 16:08:55 2014 local2.info chat[1265]: send (ATE1^M)
Mon May 26 16:08:55 2014 local2.info chat[1265]: expect (OK)
Mon May 26 16:08:55 2014 local2.info chat[1265]: ^M
Mon May 26 16:08:55 2014 local2.info chat[1265]: ATE1^M^M
Mon May 26 16:08:55 2014 local2.info chat[1265]: OK
Mon May 26 16:08:55 2014 local2.info chat[1265]:  -- got it
Mon May 26 16:08:55 2014 local2.info chat[1265]: send (AT+CGDCONT=1,"IP","internet.eplus.de"^M)
Mon May 26 16:08:56 2014 local2.info chat[1265]: timeout set to 30 seconds
Mon May 26 16:08:56 2014 local2.info chat[1265]: expect (OK)
Mon May 26 16:08:56 2014 local2.info chat[1265]: ^M
Mon May 26 16:08:56 2014 local2.info chat[1265]: AT+CGDCONT=1,"IP","internet.eplus.de"^M^M
Mon May 26 16:08:56 2014 local2.info chat[1265]: +CME ERROR
Mon May 26 16:08:56 2014 local2.info chat[1265]:  -- failed
Mon May 26 16:08:56 2014 local2.info chat[1265]: Failed (ERROR)
Mon May 26 16:08:56 2014 daemon.debug pppd[1262]: Script USE_APN=internet.eplus.de /usr/sbin/chat -t5 -v -E -f /etc/chatscripts/3g.chat finished (pid 1264), status = 0x6
Mon May 26 16:08:56 2014 daemon.err pppd[1262]: Connect script failed
Mon May 26 16:08:57 2014 daemon.info pppd[1262]: Exit.
Mon May 26 16:08:57 2014 daemon.notice netifd: Interface 'wan' is now down
Mon May 26 16:08:57 2014 daemon.notice netifd: Interface 'wan' is setting up now
Mon May 26 16:08:59 2014 daemon.notice netifd: wan (1271): Trying to set mode
Mon May 26 16:09:00 2014 daemon.notice pppd[1286]: pppd 2.4.5 started by root, uid 0
Mon May 26 16:09:01 2014 local2.info chat[1288]: abort on (BUSY)
Mon May 26 16:09:01 2014 local2.info chat[1288]: abort on (NO CARRIER)
Mon May 26 16:09:01 2014 local2.info chat[1288]: abort on (ERROR)
Mon May 26 16:09:01 2014 local2.info chat[1288]: report (CONNECT)
Mon May 26 16:09:01 2014 local2.info chat[1288]: timeout set to 10 seconds
Mon May 26 16:09:01 2014 local2.info chat[1288]: send (AT&F^M)
Mon May 26 16:09:01 2014 local2.info chat[1288]: expect (OK)
Mon May 26 16:09:01 2014 local2.info chat[1288]: AT&F^M^M
Mon May 26 16:09:01 2014 local2.info chat[1288]: OK
Mon May 26 16:09:01 2014 local2.info chat[1288]:  -- got it
Mon May 26 16:09:01 2014 local2.info chat[1288]: send (ATE1^M)
Mon May 26 16:09:01 2014 local2.info chat[1288]: expect (OK)
Mon May 26 16:09:01 2014 local2.info chat[1288]: ^M
Mon May 26 16:09:01 2014 local2.info chat[1288]: ATE1^M^M
Mon May 26 16:09:01 2014 local2.info chat[1288]: OK
Mon May 26 16:09:01 2014 local2.info chat[1288]:  -- got it
Mon May 26 16:09:01 2014 local2.info chat[1288]: send (AT+CGDCONT=1,"IP","internet.eplus.de"^M)
Mon May 26 16:09:01 2014 local2.info chat[1288]: timeout set to 30 seconds
Mon May 26 16:09:01 2014 local2.info chat[1288]: expect (OK)
Mon May 26 16:09:01 2014 local2.info chat[1288]: ^M
Mon May 26 16:09:01 2014 local2.info chat[1288]: AT+CGDCONT=1,"IP","internet.eplus.de"^M^M
Mon May 26 16:09:01 2014 local2.info chat[1288]: OK
Mon May 26 16:09:01 2014 local2.info chat[1288]:  -- got it
Mon May 26 16:09:01 2014 local2.info chat[1288]: send (ATD*99***1#^M)
Mon May 26 16:09:01 2014 local2.info chat[1288]: expect (CONNECT)
Mon May 26 16:09:01 2014 local2.info chat[1288]: ^M
Mon May 26 16:09:01 2014 local2.info chat[1288]: ATD*99***1#^M^M
Mon May 26 16:09:01 2014 local2.info chat[1288]: CONNECT
Mon May 26 16:09:01 2014 local2.info chat[1288]:  -- got it
Mon May 26 16:09:01 2014 local2.info chat[1288]: send ( ^M)
Mon May 26 16:09:01 2014 daemon.debug pppd[1286]: Script USE_APN=internet.eplus.de /usr/sbin/chat -t5 -v -E -f /etc/chatscripts/3g.chat finished (pid 1287), status = 0x0
Mon May 26 16:09:01 2014 daemon.info pppd[1286]: Serial connection established.
Mon May 26 16:09:01 2014 daemon.debug pppd[1286]: using channel 1
Mon May 26 16:09:01 2014 daemon.info pppd[1286]: Using interface 3g-wan
Mon May 26 16:09:01 2014 daemon.notice pppd[1286]: Connect: 3g-wan <--> /dev/ttyUSB0
Mon May 26 16:09:02 2014 daemon.debug pppd[1286]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x570f8cfc>]
Mon May 26 16:09:02 2014 daemon.debug pppd[1286]: rcvd [LCP ConfReq id=0x0 <mru 1440> <asyncmap 0x0> <auth chap MD5> <magic 0x2f86a40> <pcomp> <accomp>]
Mon May 26 16:09:02 2014 daemon.debug pppd[1286]: sent [LCP ConfRej id=0x0 <pcomp> <accomp>]
Mon May 26 16:09:02 2014 daemon.debug pppd[1286]: rcvd [LCP ConfNak id=0x1 <mru 1440>]
Mon May 26 16:09:02 2014 daemon.debug pppd[1286]: sent [LCP ConfReq id=0x2 <mru 1440> <asyncmap 0x0> <magic 0x570f8cfc>]
Mon May 26 16:09:02 2014 daemon.debug pppd[1286]: rcvd [LCP ConfReq id=0x1 <mru 1440> <asyncmap 0x0> <auth chap MD5> <magic 0x2f86a40>]
Mon May 26 16:09:02 2014 daemon.debug pppd[1286]: sent [LCP ConfAck id=0x1 <mru 1440> <asyncmap 0x0> <auth chap MD5> <magic 0x2f86a40>]
Mon May 26 16:09:02 2014 daemon.debug pppd[1286]: rcvd [LCP ConfAck id=0x2 <mru 1440> <asyncmap 0x0> <magic 0x570f8cfc>]
Mon May 26 16:09:02 2014 daemon.debug pppd[1286]: sent [LCP EchoReq id=0x0 magic=0x570f8cfc]
Mon May 26 16:09:02 2014 daemon.debug pppd[1286]: rcvd [LCP DiscReq id=0x2 magic=0x2f86a40]
Mon May 26 16:09:02 2014 daemon.debug pppd[1286]: rcvd [CHAP Challenge id=0x1 <baa67cf0ae78a687142d3dc2acdf5a3e>, name = "UMTS_CHAP_SRVR"]
Mon May 26 16:09:02 2014 daemon.debug pppd[1286]: sent [CHAP Response id=0x1 <436437f854ac19eb23eb63e4f9ed513a>, name = "eplus"]
Mon May 26 16:09:02 2014 daemon.debug pppd[1286]: rcvd [LCP EchoRep id=0x0 magic=0x2f86a40 57 0f 8c fc]
Mon May 26 16:09:02 2014 daemon.debug pppd[1286]: rcvd [CHAP Success id=0x1 ""]
Mon May 26 16:09:02 2014 daemon.info pppd[1286]: CHAP authentication succeeded
Mon May 26 16:09:02 2014 daemon.notice pppd[1286]: CHAP authentication succeeded
Mon May 26 16:09:02 2014 daemon.debug pppd[1286]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mon May 26 16:09:03 2014 daemon.debug pppd[1286]: sent [LCP EchoReq id=0x1 magic=0x570f8cfc]
Mon May 26 16:09:03 2014 daemon.debug pppd[1286]: rcvd [LCP EchoRep id=0x1 magic=0x2f86a40 57 0f 8c fc]
Mon May 26 16:09:03 2014 daemon.debug pppd[1286]: rcvd [IPCP ConfNak id=0x1 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
Mon May 26 16:09:03 2014 daemon.debug pppd[1286]: sent [IPCP ConfReq id=0x2 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
Mon May 26 16:09:04 2014 daemon.debug pppd[1286]: sent [LCP EchoReq id=0x2 magic=0x570f8cfc]
Mon May 26 16:09:04 2014 daemon.debug pppd[1286]: rcvd [LCP EchoRep id=0x2 magic=0x2f86a40 57 0f 8c fc]
Mon May 26 16:09:04 2014 daemon.debug pppd[1286]: rcvd [IPCP ConfNak id=0x2 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
Mon May 26 16:09:04 2014 daemon.debug pppd[1286]: sent [IPCP ConfReq id=0x3 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
Mon May 26 16:09:05 2014 daemon.debug pppd[1286]: sent [LCP EchoReq id=0x3 magic=0x570f8cfc]
Mon May 26 16:09:05 2014 daemon.debug pppd[1286]: rcvd [LCP EchoRep id=0x3 magic=0x2f86a40 57 0f 8c fc]
Mon May 26 16:09:05 2014 daemon.debug pppd[1286]: rcvd [IPCP ConfNak id=0x3 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
Mon May 26 16:09:05 2014 daemon.debug pppd[1286]: sent [IPCP ConfReq id=0x4 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
Mon May 26 16:09:06 2014 daemon.debug pppd[1286]: sent [LCP EchoReq id=0x4 magic=0x570f8cfc]
Mon May 26 16:09:06 2014 daemon.debug pppd[1286]: rcvd [LCP EchoRep id=0x4 magic=0x2f86a40 57 0f 8c fc]
Mon May 26 16:09:06 2014 daemon.debug pppd[1286]: rcvd [IPCP ConfNak id=0x4 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
Mon May 26 16:09:06 2014 daemon.debug pppd[1286]: sent [IPCP ConfReq id=0x5 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
Mon May 26 16:09:07 2014 daemon.debug pppd[1286]: rcvd [IPCP ConfReq id=0x0]
Mon May 26 16:09:07 2014 daemon.debug pppd[1286]: sent [IPCP ConfNak id=0x0 <addr 0.0.0.0>]
Mon May 26 16:09:07 2014 daemon.debug pppd[1286]: rcvd [IPCP ConfNak id=0x5 <addr 100.121.113.252> <ms-dns1 212.23.115.148> <ms-dns2 212.23.115.150>]
Mon May 26 16:09:07 2014 daemon.debug pppd[1286]: sent [IPCP ConfReq id=0x6 <addr 100.121.113.252> <ms-dns1 212.23.115.148> <ms-dns2 212.23.115.150>]
Mon May 26 16:09:07 2014 daemon.debug pppd[1286]: rcvd [IPCP ConfReq id=0x1]
Mon May 26 16:09:07 2014 daemon.debug pppd[1286]: sent [IPCP ConfAck id=0x1]
Mon May 26 16:09:07 2014 daemon.debug pppd[1286]: rcvd [IPCP ConfAck id=0x6 <addr 100.121.113.252> <ms-dns1 212.23.115.148> <ms-dns2 212.23.115.150>]
Mon May 26 16:09:07 2014 daemon.warn pppd[1286]: Could not determine remote IP address: defaulting to 10.64.64.64
Mon May 26 16:09:07 2014 daemon.notice pppd[1286]: local  IP address 100.121.113.252
Mon May 26 16:09:07 2014 daemon.notice pppd[1286]: remote IP address 10.64.64.64
Mon May 26 16:09:07 2014 daemon.notice pppd[1286]: primary   DNS address 212.23.115.148
Mon May 26 16:09:07 2014 daemon.notice pppd[1286]: secondary DNS address 212.23.115.150
Mon May 26 16:09:07 2014 daemon.debug pppd[1286]: Script /lib/netifd/ppp-up started (pid 1315)
Mon May 26 16:09:07 2014 daemon.notice netifd: Network device '3g-wan' link is up
Mon May 26 16:09:07 2014 daemon.notice netifd: Interface 'wan6' is enabled
Mon May 26 16:09:07 2014 daemon.notice netifd: Network alias '3g-wan' link is up
Mon May 26 16:09:07 2014 daemon.notice netifd: Interface 'wan6' has link connectivity 
Mon May 26 16:09:07 2014 daemon.notice netifd: Interface 'wan6' is setting up now
Mon May 26 16:09:07 2014 daemon.notice netifd: Interface 'wan' is now up
Mon May 26 16:09:07 2014 daemon.debug pppd[1286]: Script /lib/netifd/ppp-up finished (pid 1315), status = 0x1
Mon May 26 16:09:07 2014 daemon.notice odhcp6c[1333]: (re)starting transaction on 3g-wan
Mon May 26 16:09:07 2014 daemon.notice odhcp6c[1333]: Starting SOLICIT transaction (timeout 4294967295s, max rc 0)
Mon May 26 16:09:07 2014 user.notice firewall: Reloading firewall due to ifup of wan (3g-wan)
Mon May 26 16:09:08 2014 daemon.info dnsmasq[946]: exiting on receipt of SIGTERM
Mon May 26 16:09:08 2014 daemon.info dnsmasq[1382]: started, version 2.71 cachesize 150
Mon May 26 16:09:08 2014 daemon.info dnsmasq[1382]: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP no-DHCPv6 no-Lua TFTP no-conntrack no-ipset no-auth no-DNSSEC
Mon May 26 16:09:08 2014 daemon.info dnsmasq-dhcp[1382]: DHCP, IP range 192.168.1.100 -- 192.168.1.249, lease time 12h
Mon May 26 16:09:08 2014 daemon.info dnsmasq[1382]: using local addresses only for domain lan
Mon May 26 16:09:08 2014 daemon.info dnsmasq[1382]: reading /tmp/resolv.conf.auto
Mon May 26 16:09:08 2014 daemon.info dnsmasq[1382]: using local addresses only for domain lan
Mon May 26 16:09:08 2014 daemon.info dnsmasq[1382]: using nameserver 212.23.97.2#53
Mon May 26 16:09:08 2014 daemon.info dnsmasq[1382]: using nameserver 212.23.115.148#53
Mon May 26 16:09:08 2014 daemon.info dnsmasq[1382]: using nameserver 212.23.115.150#53
Mon May 26 16:09:08 2014 daemon.info dnsmasq[1382]: read /etc/hosts - 1 addresses
Mon May 26 16:09:08 2014 daemon.info dnsmasq[1382]: read /tmp/hosts/dhcp - 0 addresses
Mon May 26 16:09:08 2014 daemon.info dnsmasq-dhcp[1382]: read /etc/ethers - 0 addresses
}}}
Also my VendorId of the dongle is differnt before and after the unplugging. 
Before: 
{{{
Bus 001 Device 002: ID 12d1:1446 Huawei Technologies Co., Ltd. E1552/E1800/E173 (HSPA modem)
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
}}}
After:
{{{
Bus 001 Device 004: ID 12d1:1506 Huawei Technologies Co., Ltd. E398 LTE/UMTS/GSM Modem/Networkcard
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
}}}
I hope s.b. can help me or let me know if this is the right ticket. thanks


comment:33 Changed 3 years ago by widmark

I have the same problem on a TP-link WR1043ND rev 2.1 running Barrier Breaker RC3. The 3g-dongle (TP-link MA260) is not properly set up at boot. A manual reset of the usb-bus (writing 1 to bConfigurationValue under usb1) will make it appear, manually disconnecting the dongle and reconnecting it again also works. But no such luck with both a cold and warm boot. Adding a "sleep 1" at the end of the loop in /sbin/hotplug-call will make it appear at boot. Might this be related to "OpenWrt hotplug script fix" described in http://wiki.openwrt.org/doc/howto/mwan3 ?

comment:34 Changed 3 years ago by anonymous

I think I had the same problem on a TL WR 1043 and barrier breaker rc2. I think I solved putting following commands in rc.local

/etc/init.d/usbmode start
sleep 2
ifup 3g

comment:35 Changed 3 years ago by anonymous

I have the same problem on a TP-Link TL-MR3220 v2 running ROOter Huntsman 2014-01-25 (OpenWRT r36486) with a Sierra Wireless 250U 3g/4g-dongle. The only things that works for me is 1) manually entering ifup wan, 2) clicking connect at Network -> Interfaces, and 3) manually disconnecting and reconnecting the modem. I also noticed that if I reboot the router, the modem will not respond to the initialization command. Only after the power is cycled to the usb port will the modem connect.

comment:36 follow-up: Changed 3 years ago by anonymous

This is, what I like on Linux development: Once one found a solution to a problem, someone wants to improve things and f* it up all over again... *sigh*.

Why do we need json and fancy webinterfaces on a router os anyway? I remember times, when a was happy with nvram variables and a small and simple php-webif. I had less problems by then.
Ok, I won't change the direction...back to the renewed problem:

In http://wiki.openwrt.org/doc/recipes/3gdongle?s[]=ma260 I described how to initialize TP-Link's MA260 stick. I needs some special treatment and a standard eject never worked for me on this device.
Neither the product nor vendor id's I described in the wiki, are sent over by usb-mode.json.

BTW: an usbreset does not require the usbreset utility. usb_modeswitch has a parameter "-R" which is to be combined with -p and -v -b and -g.

The initialisation messages for MA260 (storage mode ids 2357:f000) are:

"5553424312345678000000000000061e000000000000000000000000000000"
"5553424312345678000000000000061b000000020000000000000000000000"

A standard eject won't fully initialize the device, but leave it in a state in between.

The vendor and product ID for the 3G-mode of dongle should be 2357:9000 after the mode switch.

I am not yet fully familiar with the usb-mode.json, but I'll try to make guess on how it should work. Please test the file attached, but make a backup before that.

I'll attach them a patch and full version above, as soon as I figured it out.
I apologize, that I can test it myself, since my only MA260 is connected to a router quite a few miles away from my whereabouts.

BTW: an usb reset does not require the presence of the usbreset binary - alternative ways exist:

  • echo 0 > /sys/bus/usb/devices/[enumeration]/authorized" && echo 1 > /sys/bus/usb/devices/[enumeration]/authorized"

and usb_modeswitch can be invoked with -R -p [prodid] -v [vendid] -b [bus ]-g [device]
please refer to man usb_modeswitch for details.

Changed 3 years ago by anonymous

mv usb-mode.json.custom ./usb-mode-custom.json; usbmode -l; usbmode -s -v -c ./usb-mode-custom.json; #and report back here

comment:37 Changed 3 years ago by anonymous

What I am unsure about: is
echo '2357 9000 ff' > /sys/bus/usb-serial/drivers/option1/new_id

still needed? How would I issue that? procd in some /etc/hotplug.d/21-usb3gwan? Does this still work this way?

I grepped through the code of rc3 (w/o) feeds, but could not find this vendor and product id.
Where could I find this?

BTW: on ubuntu 14.04 after update-usbids I cannot find this id either?

comment:38 in reply to: ↑ 36 Changed 3 years ago by anonymous

Replying to anonymous:

I am not yet fully familiar with the usb-mode.json, but I'll try to make guess on how it should work. Please test the file attached, but make a backup before that.

I'll attach them a patch and full version above, as soon as I figured it out.
I apologize, that I can test it myself, since my only MA260 is connected to a router quite a few miles away from my whereabouts.

If your patch for MA260 works, please submit it upstream to the usb_modeswitch developers:
http://www.draisberghof.de/usb_modeswitch/

comment:39 Changed 3 years ago by anonymous

I'll get my MA260 back for testing in the 2nd week of October. If someone else, who has more experience with json-style modswitching could have a look at it, that would be of great help.

Regarding patches to the usb_modeswitch developers:
Plain usb_modeswitch does not use json? So the workaround was already described in the link above: http://wiki.openwrt.org/doc/recipes/3gdongle?s[]=ma260 and there are references to other contributors.
Feel free to report the devs this solution, so they can integrate it into their udev collection.

comment:40 Changed 3 years ago by Tokray

Solved this one.
Have MR3020 with Barier Braker clean installed.
Followed http://wiki.openwrt.org/doc/recipes/3gdongle with MA260 (modeswitch with usb_mode.json included).

Problem: 3g WAN starts on modem replug, does not start on boot.

Solution:
vi /etc/hotplug.d/usb/20-usb_mode

Add "Sleep 5" line
before "/etc/init.d/usbmode start"

Add Comment

Modify Ticket

Action
as reopened .
Author


E-mail address and user name can be saved in the Preferences.

 
Note: See TracTickets for help on using tickets.