I am now quite certain that the problem is/was the inability of dhcp to establish a connection.
This morning, I tried to reproduce the problem, starting with booting using a direct connection to the router which runs DNS. After that, I could not make the connection fail: I brought eth0 down & up and it reconnected. I moved the cable to put the Netger GB switch (not as crappy as I had thought) between my system and the DNS Router, it just worked, I stopped the connection and restart, it worked.
Only after I cold booted did it fail to connect. The system log:
Code: Select all
Jan 30 00:54:17 puppypc2515 user.info kernel: tg3.c:v3.136 (Jan 03, 2014)
Jan 30 00:54:17 puppypc2515 user.info kernel: libphy: tg3 mdio bus: probed
Jan 30 00:54:17 puppypc2515 user.info kernel: [drm] Memory usable by graphics device = 2048M
Jan 30 00:54:17 puppypc2515 user.debug kernel: i915 0000:00:02.0: irq 43 for MSI/MSI-X
Jan 30 00:54:17 puppypc2515 user.info kernel: [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
Jan 30 00:54:17 puppypc2515 user.info kernel: [drm] Driver supports precise vblank timestamp query.
Jan 30 00:54:17 puppypc2515 user.info kernel: vgaarb: device changed decodes: PCI:0000:00:02.0,olddecodes=io+mem,decodes=io+mem:owns=io+mem
Jan 30 00:54:17 puppypc2515 user.info kernel: [drm] Skipping LVDS initialization for Hewlett-Packard t5745
Jan 30 00:54:17 puppypc2515 user.info kernel: tg3 0000:04:00.0 eth0: Tigon3 [partno(BCM57780) rev 57780001] (PCI Express) MAC address 9c:8e:99:c5:6e:19
Jan 30 00:54:17 puppypc2515 user.info kernel: tg3 0000:04:00.0 eth0: attached PHY driver [Broadcom BCM57780] (mii_bus:phy_addr=400:01)
Jan 30 00:54:17 puppypc2515 user.info kernel: tg3 0000:04:00.0 eth0: RXcsums[1] LinkChgREG[0] MIirq[0] ASF[0] TSOcap[1]
Jan 30 00:54:17 puppypc2515 user.info kernel: tg3 0000:04:00.0 eth0: dma_rwctrl[76180000] dma_mask[64-bit]
Jan 30 00:54:17 puppypc2515 user.info kernel: fbcon: inteldrmfb (fb0) is primary device
Jan 30 00:54:17 puppypc2515 user.info kernel: input: PS/2 Logitech Mouse as /devices/platform/i8042/serio1/input/input4
Jan 30 00:54:17 puppypc2515 user.info kernel: Console: switching to colour frame buffer device 128x48
Jan 30 00:54:17 puppypc2515 user.info kernel: i915 0000:00:02.0: fb0: inteldrmfb frame buffer device
Jan 30 00:54:17 puppypc2515 user.info kernel: i915 0000:00:02.0: registered panic notifier
Jan 30 00:54:17 puppypc2515 user.info kernel: ACPI: Video Device [GFX0] (multi-head: yes rom: no post: no)
Jan 30 00:54:17 puppypc2515 user.info kernel: floppy0: no floppy controllers found
Jan 30 00:54:17 puppypc2515 user.info kernel: input: Video Bus as /devices/LNXSYSTM:00/device:00/PNP0A08:00/LNXVIDEO:00/input/input5
Jan 30 00:54:17 puppypc2515 user.info kernel: [drm] Initialized i915 1.6.0 20080730 for 0000:00:02.0 on minor 0
Jan 30 00:54:17 puppypc2515 user.debug kernel: snd_hda_intel 0000:00:1b.0: irq 44 for MSI/MSI-X
Jan 30 00:54:17 puppypc2515 user.info kernel: input: PC Speaker as /devices/platform/pcspkr/input/input6
Jan 30 00:54:17 puppypc2515 user.debug kernel: tg3 0000:04:00.0: irq 45 for MSI/MSI-X
Jan 30 00:54:17 puppypc2515 user.info kernel: tg3 0000:04:00.0 eth0: Link is down
Jan 30 00:54:17 puppypc2515 user.debug kernel: tg3 0000:04:00.0: irq 45 for MSI/MSI-X
Jan 30 00:54:17 puppypc2515 user.debug kernel: tg3 0000:04:00.0: irq 45 for MSI/MSI-X
Jan 30 00:54:17 puppypc2515 user.info kernel: tg3 0000:04:00.0 eth0: Link is down
Jan 30 00:54:26 puppypc2515 user.debug kernel: tg3 0000:04:00.0: irq 45 for MSI/MSI-X
Jan 29 09:54:26 puppypc2515 daemon.info dhcpcd[5951]: version 6.7.1-dropwait starting
Jan 30 00:54:26 puppypc2515 user.info kernel: cfg80211: Calling CRDA to update world regulatory domain
Jan 29 09:54:26 puppypc2515 daemon.warn dhcpcd[5951]: all: IPv6 kernel autoconf disabled
Jan 29 09:54:26 puppypc2515 daemon.debug dhcpcd[5951]: /proc/sys/net/ipv6/conf/all/accept_ra: No such file or directory
Jan 29 09:54:26 puppypc2515 daemon.warn dhcpcd[5951]: eth0: IPv6 kernel autoconf disabled
Jan 29 09:54:26 puppypc2515 daemon.debug dhcpcd[5951]: /proc/sys/net/ipv6/conf/eth0/accept_ra: No such file or directory
Jan 29 09:54:26 puppypc2515 daemon.info dhcpcd[5951]: eth0: adding address fe80::9e8e:99ff:fec5:6e19
Jan 29 09:54:26 puppypc2515 daemon.debug dhcpcd[5951]: eth0: pltime infinity, vltime infinity
Jan 29 09:54:26 puppypc2515 daemon.err dhcpcd[5951]: if_addaddress6: Operation not supported
Jan 29 09:54:26 puppypc2515 daemon.debug dhcpcd[5951]: eth0: executing `/lib/dhcpcd/dhcpcd-run-hooks' PREINIT
Jan 29 09:54:27 puppypc2515 daemon.debug dhcpcd[5951]: eth0: executing `/lib/dhcpcd/dhcpcd-run-hooks' NOCARRIER
Jan 29 09:54:27 puppypc2515 daemon.info dhcpcd[5951]: eth0: waiting for carrier
Jan 29 09:54:36 puppypc2515 user.notice powerapplet: Abort, unable to open /proc/acpi/battery
Jan 30 00:54:38 puppypc2515 user.info kernel: ip_tables: (C) 2000-2006 Netfilter Core Team
Jan 29 09:54:52 puppypc2515 daemon.info dhcpcd[5951]: eth0: carrier acquired
Jan 30 00:54:52 puppypc2515 user.info kernel: tg3 0000:04:00.0 eth0: Link is up at 100 Mbps, full duplex
Jan 30 00:54:52 puppypc2515 user.info kernel: tg3 0000:04:00.0 eth0: Flow control is on for TX and on for RX
Jan 29 09:54:52 puppypc2515 daemon.warn dhcpcd[5951]: all: IPv6 kernel autoconf disabled
Jan 29 09:54:52 puppypc2515 daemon.debug dhcpcd[5951]: /proc/sys/net/ipv6/conf/all/accept_ra: No such file or directory
Jan 29 09:54:52 puppypc2515 daemon.warn dhcpcd[5951]: eth0: IPv6 kernel autoconf disabled
Jan 29 09:54:52 puppypc2515 daemon.debug dhcpcd[5951]: /proc/sys/net/ipv6/conf/eth0/accept_ra: No such file or directory
Jan 29 09:54:52 puppypc2515 daemon.debug dhcpcd[5951]: eth0: executing `/lib/dhcpcd/dhcpcd-run-hooks' CARRIER
Jan 29 09:54:52 puppypc2515 daemon.info dhcpcd[5951]: DUID 00:01:00:01:21:ff:50:c7:9c:8e:99:c5:6e:19
Jan 29 09:54:52 puppypc2515 daemon.info dhcpcd[5951]: eth0: IAID 99:c5:6e:19
Jan 29 09:54:52 puppypc2515 daemon.debug dhcpcd[5951]: eth0: delaying IPv4 for 0.6 seconds
Jan 29 09:54:52 puppypc2515 daemon.debug dhcpcd[5951]: eth0: using hwaddr 9c:8e:99:c5:6e:19
Jan 29 09:54:52 puppypc2515 daemon.info dhcpcd[5951]: eth0: soliciting a DHCP lease
Jan 29 09:54:52 puppypc2515 daemon.debug dhcpcd[5951]: eth0: sending DISCOVER (xid 0x9a23df9), next in 4.6 seconds
Jan 29 09:54:53 puppypc2515 daemon.info dhcpcd[5951]: eth0: offered 192.168.1.101 from 192.168.1.1
Jan 29 09:54:53 puppypc2515 daemon.debug dhcpcd[5951]: eth0: sending REQUEST (xid 0x9a23df9), next in 4.8 seconds
Jan 29 09:54:53 puppypc2515 daemon.debug dhcpcd[5951]: eth0: acknowledged 192.168.1.101 from 192.168.1.1
Jan 29 09:54:53 puppypc2515 daemon.debug dhcpcd[5951]: eth0: probing for 192.168.1.101
Jan 29 09:54:53 puppypc2515 daemon.debug dhcpcd[5951]: eth0: ARP probing 192.168.1.101 (1 of 3), next in 1.0 seconds
Jan 29 09:54:54 puppypc2515 daemon.debug dhcpcd[5951]: eth0: ARP probing 192.168.1.101 (2 of 3), next in 1.6 seconds
Jan 29 09:54:56 puppypc2515 daemon.debug dhcpcd[5951]: eth0: ARP probing 192.168.1.101 (3 of 3), next in 2.0 seconds
Jan 29 09:54:57 puppypc2515 daemon.err dhcpcd[5951]: timed out
Jan 29 09:54:57 puppypc2515 daemon.info dhcpcd[5951]: exited
Jan 29 09:55:43 puppypc2515 daemon.info dhcpcd[7256]: version 6.7.1-dropwait starting
Jan 29 09:55:43 puppypc2515 daemon.warn dhcpcd[7256]: all: IPv6 kernel autoconf disabled
Jan 29 09:55:43 puppypc2515 daemon.debug dhcpcd[7256]: /proc/sys/net/ipv6/conf/all/accept_ra: No such file or directory
Jan 29 09:55:43 puppypc2515 daemon.warn dhcpcd[7256]: eth0: IPv6 kernel autoconf disabled
Jan 29 09:55:43 puppypc2515 daemon.debug dhcpcd[7256]: /proc/sys/net/ipv6/conf/eth0/accept_ra: No such file or directory
Jan 29 09:55:43 puppypc2515 daemon.info dhcpcd[7256]: eth0: adding address fe80::9e8e:99ff:fec5:6e19
Jan 29 09:55:43 puppypc2515 daemon.debug dhcpcd[7256]: eth0: pltime infinity, vltime infinity
Jan 29 09:55:43 puppypc2515 daemon.err dhcpcd[7256]: if_addaddress6: Operation not supported
Jan 29 09:55:43 puppypc2515 daemon.debug dhcpcd[7256]: eth0: executing `/lib/dhcpcd/dhcpcd-run-hooks' PREINIT
Jan 29 09:55:43 puppypc2515 daemon.debug dhcpcd[7256]: eth0: executing `/lib/dhcpcd/dhcpcd-run-hooks' CARRIER
Jan 29 09:55:43 puppypc2515 daemon.info dhcpcd[7256]: DUID 00:01:00:01:21:ff:50:c7:9c:8e:99:c5:6e:19
Jan 29 09:55:43 puppypc2515 daemon.info dhcpcd[7256]: eth0: IAID 99:c5:6e:19
Jan 29 09:55:43 puppypc2515 daemon.debug dhcpcd[7256]: eth0: delaying IPv4 for 1.0 seconds
Jan 29 09:55:44 puppypc2515 daemon.debug dhcpcd[7256]: eth0: using hwaddr 9c:8e:99:c5:6e:19
Jan 29 09:55:44 puppypc2515 daemon.info dhcpcd[7256]: eth0: soliciting a DHCP lease
Jan 29 09:55:44 puppypc2515 daemon.debug dhcpcd[7256]: eth0: sending DISCOVER (xid 0xfa11f8e), next in 4.2 seconds
Jan 29 09:55:45 puppypc2515 daemon.info dhcpcd[7256]: eth0: offered 192.168.1.101 from 192.168.1.1
Jan 29 09:55:45 puppypc2515 daemon.debug dhcpcd[7256]: eth0: sending REQUEST (xid 0xfa11f8e), next in 3.3 seconds
Jan 29 09:55:45 puppypc2515 daemon.debug dhcpcd[7256]: eth0: acknowledged 192.168.1.101 from 192.168.1.1
Jan 29 09:55:45 puppypc2515 daemon.debug dhcpcd[7256]: eth0: probing for 192.168.1.101
Jan 29 09:55:45 puppypc2515 daemon.debug dhcpcd[7256]: eth0: ARP probing 192.168.1.101 (1 of 3), next in 1.5 seconds
Jan 29 09:55:47 puppypc2515 daemon.debug dhcpcd[7256]: eth0: ARP probing 192.168.1.101 (2 of 3), next in 1.7 seconds
Jan 29 09:55:49 puppypc2515 daemon.debug dhcpcd[7256]: eth0: ARP probing 192.168.1.101 (3 of 3), next in 2.0 seconds
Jan 29 09:55:51 puppypc2515 daemon.info dhcpcd[7256]: eth0: leased 192.168.1.101 for 86400 seconds
Jan 29 09:55:51 puppypc2515 daemon.debug dhcpcd[7256]: eth0: renew in 43200 seconds, rebind in 75600 seconds
Jan 29 09:55:51 puppypc2515 daemon.debug dhcpcd[7256]: eth0: writing lease `/var/lib/dhcpcd/dhcpcd-eth0.lease'
Jan 29 09:55:51 puppypc2515 daemon.debug dhcpcd[7256]: eth0: adding IP address 192.168.1.101/24
Jan 29 09:55:51 puppypc2515 daemon.info dhcpcd[7256]: eth0: adding route to 192.168.1.0/24
Jan 29 09:55:51 puppypc2515 daemon.info dhcpcd[7256]: eth0: adding default route via 192.168.1.1
Jan 29 09:55:51 puppypc2515 daemon.debug dhcpcd[7256]: eth0: executing `/lib/dhcpcd/dhcpcd-run-hooks' BOUND
Jan 29 09:55:51 puppypc2515 daemon.debug dhcpcd[7256]: forking to background
Jan 29 09:55:51 puppypc2515 daemon.info dhcpcd[7256]: forked to background, child pid 7367
Jan 29 09:55:51 puppypc2515 daemon.debug dhcpcd[7367]: eth0: ARP announcing 192.168.1.101 (1 of 2), next in 2.0 seconds
Jan 29 09:55:53 puppypc2515 daemon.debug dhcpcd[7367]: eth0: ARP announcing 192.168.1.101 (2 of 2)
The time stamps show that my hardware time clock is messed up and the log starts at 00:accurate minutes: seconds
This is totally confusing: the connection is not yet established, but it seams to be "Calling CRDA to update world regulatory domain". Huh?
Code: Select all
Jan 30 00:54:26 puppypc2515 user.debug kernel: tg3 0000:04:00.0: irq 45 for MSI/MSI-X
Jan 29 09:54:26 puppypc2515 daemon.info dhcpcd[5951]: version 6.7.1-dropwait starting
Jan 30 00:54:26 puppypc2515 user.info kernel: cfg80211: Calling CRDA to update world regulatory domain
Jan 29 09:54:26 puppypc2515 daemon.warn dhcpcd[5951]: all: IPv6 kernel autoconf disabled
then (referring to the full log) it tries to connect, fails at 09:54:57 then at 09:55:43 and finally acquires a lease at 09:55:51
It will work now even with a cold boot, and it will continue to because, at the end of the log we see
- adding IP address 192.168.1.101/24
adding route to 192.168.1.0/24
adding default route via 192.168.1.1
I am done with this, at least for now. I think that shutting down and properly saving the session will keep this from happening again.
Finally s243a, "off topic" ? How could we know if something is off topic until we finally get to the root cause of a problem? Oh, I didn't select Tahr 6.0.6 because I didn't see a PAE version. Thanks for posting,
Regards,
- Rob M.
Puppy in My Pocket