Modify

Opened 6 years ago

Closed 6 years ago

Last modified 4 years ago

#10383 closed defect (fixed)

Telnetd and dropbear does not start until 'wan' interface gets an IP address

Reported by: duvi Owned by: developers
Priority: normal Milestone: Barrier Breaker 14.07
Component: packages Version: Trunk
Keywords: Cc:

Description

Fresh install of trunk t28879 on a TL-MR3420, all default configs.

The 'lan' interface (4 switch ports) has the address of 192.168.1.1 which is pingable, but I cannot telnet/ssh in.
The 'wan' port has to get an address over dhcp, and only this triggers telnet and dropbear daemons on the router. After 'wan' has an address, telnet runs.

There is no firewall or dnsmasq installed, I want to use it as an AP only.

According to the log it seems that other services can also start only after the DHCP IP is received.
I think these services should not depend on whather 'wan' has an IP or not, they should start anyway.

Jan  1 00:02:04 OpenWrt user.info sysinit sevices: Sending select for a.a.a.a...
Jan  1 00:02:04 OpenWrt user.info sysinit: Lease of a.a.a.a obtained, lease time 1800
Jan  1 00:02:04 OpenWrt user.info sysinit: udhcpc: ifconfig eth1 a.a.a.a netmask 255.255.255.0 broadcast b.b.b.b
Jan  1 00:02:04 OpenWrt user.info sysinit: udhcpc: setting default routers: c.c.c.c
Jan  1 00:02:04 OpenWrt user.info sysinit: udhcpc: setting dns servers: x.x.x.x y.y.y.y
Jan  1 00:02:05 OpenWrt user.info sysinit: udhcpc: setting dns domain: z.z.z.z
Jan  1 00:02:05 OpenWrt user.notice ifup: Allowing Router Advertisements on wan (eth1)
Jan  1 00:02:05 OpenWrt user.info sysinit: 'radio0' is disabled
Jan  1 00:02:06 OpenWrt user.info sysinit: 'radio0' is disabled
Jan  1 00:02:06 OpenWrt authpriv.info dropbear[885]: Running in background
Jan  1 00:02:06 OpenWrt user.info sysinit: setting up led USB
Jan  1 00:02:07 OpenWrt kern.debug kernel: ar71xx-wdt: enabling watchdog timer

Attachments (0)

Change History (9)

comment:1 Changed 6 years ago by jow

Those services do not depend on any interface, I rather think you installed some service which blocks init until connectivity is available.

comment:2 Changed 6 years ago by duvi

And which one would that be?

root@OpenWrt:/# opkg list
base-files - 91-r28879
base-files-network - 2
busybox - 1.19.3-3
crda - 1.1.1-1
dropbear - 0.53.1-6
hotplug2 - 1.0-beta-4
iw - 3.1-2
kernel - 2.6.39.4-1
kmod-ath - 2.6.39.4+2011-11-04-1
kmod-ath9k - 2.6.39.4+2011-11-04-1
kmod-ath9k-common - 2.6.39.4+2011-11-04-1
kmod-button-hotplug - 2.6.39.4-3
kmod-cfg80211 - 2.6.39.4+2011-11-04-1
kmod-crypto-aes - 2.6.39.4-1
kmod-crypto-arc4 - 2.6.39.4-1
kmod-crypto-core - 2.6.39.4-1
kmod-input-core - 2.6.39.4-1
kmod-input-gpio-keys-polled - 2.6.39.4-1
kmod-input-polldev - 2.6.39.4-1
kmod-leds-gpio - 2.6.39.4-1
kmod-ledtrig-usbdev - 2.6.39.4-1
kmod-mac80211 - 2.6.39.4+2011-11-04-1
kmod-nls-base - 2.6.39.4-1
kmod-usb-core - 2.6.39.4-1
kmod-usb2 - 2.6.39.4-1
libc - 0.9.32-91
libgcc - 4.5-linaro-91
libnl-tiny - 0.1-2
libpcap - 1.1.1-1
libuci - 2011-10-21.2-1
mtd - 16
opkg - 618-2
swconfig - 10
uci - 2011-10-21.2-1
wireless-tools - 29-4
wiviz - 1.0-1
wpad-mini - 20111103-1

comment:3 Changed 6 years ago by duvi

'SYS' led is blinking also, until that IP is received.

comment:4 Changed 6 years ago by jow

Well first of all paste a more complete syslog.

comment:5 Changed 6 years ago by duvi

I left the router on for 13 minutes without the wan cable attached. SYS led blinking, no telnet or ssh (on 'lan').
Than at 00:13:50 I plugged in the wan cable, it got the IP, and voila, ssh started running.

root@OpenWrt:~# logread
Jan  1 00:00:11 OpenWrt syslog.info syslogd started: BusyBox v1.19.3
Jan  1 00:00:11 OpenWrt kern.notice kernel: klogd started: BusyBox v1.19.3 (2011-11-09 12:55:29 CET)
Jan  1 00:00:11 OpenWrt kern.notice kernel: Linux version 2.6.39.4 (duvi@anneke) (gcc version 4.5.4 20110808 (prerelease) (Linaro GCC 4.5-2011.08) ) #1 Wed Nov 9 13:11:17 CET 2011
Jan  1 00:00:11 OpenWrt kern.debug kernel: prom: fw_arg0=00000008, fw_arg1=a1f87fb0, fw_arg2=a1f88470, fw_arg3=00000004
Jan  1 00:00:11 OpenWrt kern.debug kernel: MyLoader: sysp=f0f0f0f0, boardp=f0f0f0f0, parts=f0f0f0f0
Jan  1 00:00:11 OpenWrt kern.info kernel: bootconsole [early0] enabled
Jan  1 00:00:11 OpenWrt kern.info kernel: CPU revision is: 00019374 (MIPS 24Kc)
Jan  1 00:00:11 OpenWrt kern.info kernel: SoC: Atheros AR7241 rev 1
Jan  1 00:00:11 OpenWrt kern.info kernel: Clocks: CPU:400.000MHz, DDR:400.000MHz, AHB:200.000MHz, Ref:5.000MHz
Jan  1 00:00:11 OpenWrt kern.info kernel: Determined physical RAM map:
Jan  1 00:00:11 OpenWrt kern.info kernel:  memory: 02000000 @ 00000000 (usable)
Jan  1 00:00:11 OpenWrt kern.info kernel: Initrd not found or empty - disabling initrd
Jan  1 00:00:11 OpenWrt kern.warn kernel: Zone PFN ranges:
Jan  1 00:00:11 OpenWrt kern.warn kernel:   Normal   0x00000000 -> 0x00002000
Jan  1 00:00:11 OpenWrt kern.warn kernel: Movable zone start PFN for each node
Jan  1 00:00:11 OpenWrt kern.warn kernel: early_node_map[1] active PFN ranges
Jan  1 00:00:11 OpenWrt kern.warn kernel:     0: 0x00000000 -> 0x00002000
Jan  1 00:00:11 OpenWrt kern.debug kernel: On node 0 totalpages: 8192
Jan  1 00:00:11 OpenWrt kern.debug kernel: free_area_init_node: node 0, pgdat 802b44d0, node_mem_map 81000000
Jan  1 00:00:11 OpenWrt kern.debug kernel:   Normal zone: 64 pages used for memmap
Jan  1 00:00:11 OpenWrt kern.debug kernel:   Normal zone: 0 pages reserved
Jan  1 00:00:11 OpenWrt kern.debug kernel:   Normal zone: 8128 pages, LIFO batch:0
Jan  1 00:00:11 OpenWrt kern.debug kernel: pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
Jan  1 00:00:11 OpenWrt kern.debug kernel: pcpu-alloc: [0] 0
Jan  1 00:00:11 OpenWrt kern.warn kernel: Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 8128
Jan  1 00:00:11 OpenWrt kern.notice kernel: Kernel command line:  board=TL-MR3420 console=ttyS0,115200 rootfstype=squashfs,jffs2 noinitrd
Jan  1 00:00:11 OpenWrt kern.info kernel: PID hash table entries: 128 (order: -3, 512 bytes)
Jan  1 00:00:11 OpenWrt kern.info kernel: Dentry cache hash table entries: 4096 (order: 2, 16384 bytes)
Jan  1 00:00:11 OpenWrt kern.info kernel: Inode-cache hash table entries: 2048 (order: 1, 8192 bytes)
Jan  1 00:00:11 OpenWrt kern.warn kernel: Primary instruction cache 64kB, VIPT, 4-way, linesize 32 bytes.
Jan  1 00:00:11 OpenWrt kern.warn kernel: Primary data cache 32kB, 4-way, VIPT, cache aliases, linesize 32 bytes
Jan  1 00:00:11 OpenWrt kern.info kernel: Writing ErrCtl register=00000000
Jan  1 00:00:11 OpenWrt kern.info kernel: Readback ErrCtl register=00000000
Jan  1 00:00:11 OpenWrt kern.info kernel: Memory: 29384k/32768k available (2000k kernel code, 3384k reserved, 386k data, 180k init, 0k highmem)
Jan  1 00:00:11 OpenWrt kern.info kernel: SLUB: Genslabs=9, HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
Jan  1 00:00:11 OpenWrt kern.info kernel: NR_IRQS:80
Jan  1 00:00:11 OpenWrt kern.info kernel: Calibrating delay loop... 265.42 BogoMIPS (lpj=1327104)
Jan  1 00:00:11 OpenWrt kern.info kernel: pid_max: default: 32768 minimum: 301
Jan  1 00:00:11 OpenWrt kern.info kernel: Mount-cache hash table entries: 512
Jan  1 00:00:11 OpenWrt kern.info kernel: NET: Registered protocol family 16
Jan  1 00:00:11 OpenWrt kern.info kernel: MIPS: machine is TP-LINK TL-MR3420
Jan  1 00:00:11 OpenWrt kern.warn kernel: registering PCI controller with io_map_base unset
Jan  1 00:00:11 OpenWrt kern.info kernel: bio: create slab <bio-0> at 0
Jan  1 00:00:11 OpenWrt kern.debug kernel: pci 0000:00:00.0: [168c:ff1c] type 0 class 0x000200
Jan  1 00:00:11 OpenWrt kern.info kernel: pci 0000:00:00.0: fixup device configuration
Jan  1 00:00:11 OpenWrt kern.debug kernel: pci 0000:00:00.0: reg 10: [mem 0x00000000-0x0000ffff 64bit]
Jan  1 00:00:11 OpenWrt kern.debug kernel: pci 0000:00:00.0: supports D1
Jan  1 00:00:11 OpenWrt kern.debug kernel: pci 0000:00:00.0: PME# supported from D0 D1 D3hot
Jan  1 00:00:11 OpenWrt kern.debug kernel: pci 0000:00:00.0: PME# disabled
Jan  1 00:00:11 OpenWrt kern.info kernel: pci 0000:00:00.0: BAR 0: assigned [mem 0x10000000-0x1000ffff 64bit]
Jan  1 00:00:11 OpenWrt kern.info kernel: pci 0000:00:00.0: BAR 0: set to [mem 0x10000000-0x1000ffff 64bit] (PCI address [0x10000000-0x1000ffff])
Jan  1 00:00:11 OpenWrt kern.info kernel: PCI: mapping irq 72 to pin1@0000:00:00.0
Jan  1 00:00:11 OpenWrt kern.info kernel: Switching to clocksource MIPS
Jan  1 00:00:11 OpenWrt kern.info kernel: NET: Registered protocol family 2
Jan  1 00:00:11 OpenWrt kern.info kernel: IP route cache hash table entries: 1024 (order: 0, 4096 bytes)
Jan  1 00:00:11 OpenWrt kern.info kernel: TCP established hash table entries: 1024 (order: 1, 8192 bytes)
Jan  1 00:00:11 OpenWrt kern.info kernel: TCP bind hash table entries: 1024 (order: 0, 4096 bytes)
Jan  1 00:00:11 OpenWrt kern.debug kernel: ath: EEPROM regdomain: 0x0
Jan  1 00:00:11 OpenWrt kern.debug kernel: ath: EEPROM indicates default country code should be used
Jan  1 00:00:11 OpenWrt kern.debug kernel: ath: doing EEPROM country->regdmn map search
Jan  1 00:00:11 OpenWrt kern.debug kernel: ath: country maps to regdmn code: 0x3a
Jan  1 00:00:11 OpenWrt kern.debug kernel: ath: Country alpha2 being used: US
Jan  1 00:00:11 OpenWrt kern.debug kernel: ath: Regpair used: 0x3a
Jan  1 00:00:11 OpenWrt kern.debug kernel: ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
Jan  1 00:00:11 OpenWrt kern.debug kernel: Registered led device: ath9k-phy0
Jan  1 00:00:11 OpenWrt kern.info kernel: ieee80211 phy0: Atheros AR9287 Rev:2 mem=0xb0000000, irq=72
Jan  1 00:00:11 OpenWrt kern.info kernel: cfg80211: Calling CRDA for country: US
Jan  1 00:00:11 OpenWrt kern.info kernel: ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
Jan  1 00:00:11 OpenWrt kern.info kernel: ar71xx-ehci ar71xx-ehci: Atheros AR91xx built-in EHCI controller
Jan  1 00:00:11 OpenWrt kern.info kernel: ar71xx-ehci ar71xx-ehci: new USB bus registered, assigned bus number 1
Jan  1 00:00:11 OpenWrt kern.info kernel: ar71xx-ehci ar71xx-ehci: irq 3, io mem 0x1b000000
Jan  1 00:00:11 OpenWrt kern.info kernel: cfg80211: Regulatory domain changed to country: US
Jan  1 00:00:11 OpenWrt kern.info kernel: cfg80211:     (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
Jan  1 00:00:11 OpenWrt kern.info kernel: cfg80211:     (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2700 mBm)
Jan  1 00:00:11 OpenWrt kern.info kernel: cfg80211:     (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 1700 mBm)
Jan  1 00:00:11 OpenWrt kern.info kernel: cfg80211:     (5250000 KHz - 5330000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Jan  1 00:00:11 OpenWrt kern.info kernel: cfg80211:     (5490000 KHz - 5600000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Jan  1 00:00:11 OpenWrt kern.info kernel: cfg80211:     (5650000 KHz - 5710000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Jan  1 00:00:11 OpenWrt kern.info kernel: cfg80211:     (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 3000 mBm)
Jan  1 00:00:11 OpenWrt kern.info kernel: ar71xx-ehci ar71xx-ehci: USB 2.0 started, EHCI 1.00
Jan  1 00:00:11 OpenWrt kern.info kernel: hub 1-0:1.0: USB hub found
Jan  1 00:00:11 OpenWrt kern.info kernel: hub 1-0:1.0: 1 port detected
Jan  1 00:00:11 OpenWrt user.notice ifup: Enabling Router Solicitations on loopback (lo)
Jan  1 00:00:11 OpenWrt kern.info kernel: eth0: link up (1000Mbps/Full duplex)
Jan  1 00:00:12 OpenWrt kern.info kernel: device eth0 entered promiscuous mode
Jan  1 00:00:12 OpenWrt kern.info kernel: br-lan: port 1(eth0) entering forwarding state
Jan  1 00:00:12 OpenWrt kern.info kernel: br-lan: port 1(eth0) entering forwarding state
Jan  1 00:00:12 OpenWrt user.info sysinit: udhcpc (v1.19.3) started
Jan  1 00:00:12 OpenWrt user.info sysinit: Sending discover...
Jan  1 00:00:13 OpenWrt user.notice ifup: Enabling Router Solicitations on lan (br-lan)
Jan  1 00:00:15 OpenWrt user.info sysinit: Sending discover...
Jan  1 00:00:18 OpenWrt user.info sysinit: Sending discover...
Jan  1 00:13:50 OpenWrt kern.info kernel: eth1: link up (100Mbps/Full duplex)
Jan  1 00:14:22 OpenWrt user.info sysinit: Sending select for a.a.a.a...
Jan  1 00:14:22 OpenWrt user.info sysinit: Lease of a.a.a.a obtained, lease time 1800
Jan  1 00:14:22 OpenWrt user.info sysinit: udhcpc: ifconfig eth1 a.a.a.a netmask 255.255.255.0 broadcast a.a.a.a
Jan  1 00:14:23 OpenWrt user.info sysinit: udhcpc: setting default routers: a.a.a.a
Jan  1 00:14:23 OpenWrt user.info sysinit: udhcpc: setting dns servers: a.a.a.a a.a.a.a
Jan  1 00:14:23 OpenWrt user.info sysinit: udhcpc: setting dns domain: a.a.a.a
Jan  1 00:14:23 OpenWrt user.notice ifup: Allowing Router Advertisements on wan (eth1)
Jan  1 00:14:23 OpenWrt user.info sysinit: 'radio0' is disabled
Jan  1 00:14:24 OpenWrt user.info sysinit: 'radio0' is disabled
Jan  1 00:14:25 OpenWrt authpriv.info dropbear[886]: Running in background
Jan  1 00:14:25 OpenWrt user.info sysinit: setting up led USB
Jan  1 00:14:25 OpenWrt kern.debug kernel: ar71xx-wdt: enabling watchdog timer
Nov  9 13:27:21 OpenWrt authpriv.info dropbear[913]: Child connection from 192.168.1.83:1817
Nov  9 13:27:29 OpenWrt authpriv.notice dropbear[913]: Password auth succeeded for 'root' from 192.168.1.83:1817

comment:6 Changed 6 years ago by Chris Luke <chris_luke@…>

I came across this too last night having updated to trunk. The hack resolution is to kill udhcpc and then the rest of the boot scripts continue.

I suspect this is a regression caused by changeset [28866] which has the effect of moving the launch of udhcpc out from an eval which was introduced in changeset [5494] to counter the same problem.

I also discovered that the use of '-t 0' on the udhcpc command line in /lib/network/config.sh contributes to this. I now run with '-t 2' and it appears to function correctly.

comment:7 Changed 6 years ago by Chris Luke <chris_luke@…>

And I have worked out why -t 0 makes it wait indefinitely. The patch 240-udhcpc_retries.patch added to busybox in [28513] looks like it was intended to allow for DHCP DISCOVERs to be sent with a 0-retries option - one would imagine to cause it to background immediately, or very quickly. However, the effect is that the code that backgrounds when no lease is found (-b option) is never reached. Ergo, once the & option in the boot script stopping being effective, it never backgrounded at boot, thus holding up the entire boot process.

In that patch https://dev.openwrt.org/browser/trunk/package/busybox/patches/240-udhcpc_retries.patch?rev=28866, I would change

if (!discover_retries || packet_num < discover_retries) { 

to

if ((!discover_retries && !packet_num) || packet_num < discover_retries) { 

so that after a single attempt times out and if -t 0 is specified, it goes into the background. I would imagine this is close to the intention.

For clarity, the code in stock busybox reads:

			case INIT_SELECTING:
				if (packet_num < discover_retries) {
					if (packet_num == 0)
						xid = random_xid();
					/* broadcast */
					send_discover(xid, requested_ip);
					timeout = discover_timeout;
					packet_num++;
					continue;
				}
 leasefail:
				udhcp_run_script(NULL, "leasefail");
#if BB_MMU /* -b is not supported on NOMMU */
				if (opt & OPT_b) { /* background if no lease */
					bb_info_msg("No lease, forking to background");
					client_background();
					/* do not background again! */
					opt = ((opt & ~OPT_b) | OPT_f);
				} else
#endif
				if (opt & OPT_n) { /* abort if no lease */
					bb_info_msg("No lease, failing");
					retval = 1;
					goto ret;
				}

the patch in openwrt trunk makes it look like this:

			case INIT_SELECTING:
				if (!discover_retries || packet_num < discover_retries) {
					if (packet_num == 0)
						xid = random_xid();
					/* broadcast */
					send_discover(xid, requested_ip);
					timeout = discover_timeout;
					packet_num++;
					continue;
				}
 leasefail:
				udhcp_run_script(NULL, "leasefail");
#if BB_MMU /* -b is not supported on NOMMU */
				if (opt & OPT_b) { /* background if no lease */
					bb_info_msg("No lease, forking to background");
					client_background();
					/* do not background again! */
					opt = ((opt & ~OPT_b) | OPT_f);
				} else
#endif
				if (opt & OPT_n) { /* abort if no lease */
					bb_info_msg("No lease, failing");
					retval = 1;
					goto ret;
				}

and my suggestion would change it to

			case INIT_SELECTING:
				if ((!discover_retries && !packet_num) || packet_num < discover_retries) {
					if (packet_num == 0)
						xid = random_xid();
					/* broadcast */
					send_discover(xid, requested_ip);
					timeout = discover_timeout;
					packet_num++;
					continue;
				}
 leasefail:
				udhcp_run_script(NULL, "leasefail");
#if BB_MMU /* -b is not supported on NOMMU */
				if (opt & OPT_b) { /* background if no lease */
					bb_info_msg("No lease, forking to background");
					client_background();
					/* do not background again! */
					opt = ((opt & ~OPT_b) | OPT_f);
				} else
#endif
				if (opt & OPT_n) { /* abort if no lease */
					bb_info_msg("No lease, failing");
					retval = 1;
					goto ret;
				}

Chris.

comment:8 Changed 6 years ago by nico

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

Should be fixed in r28942

comment:9 Changed 4 years ago by jow

  • Milestone changed from Attitude Adjustment 12.09 to Barrier Breaker 14.07

Milestone Attitude Adjustment 12.09 deleted

Add Comment

Modify Ticket

Action
as closed .
The resolution will be deleted. Next status will be 'reopened'.
Author


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

 
Note: See TracTickets for help on using tickets.