System Log Puzzler

Post Reply
Tomken
Posts: 467
Joined: Tue Jul 26, 2011 10:31 am
Location: Co Durham

System Log Puzzler

Post by Tomken »

Hi billion_fan, - The background -

Not really getting the sync speeds I'm used to getting having moved back into a rebuilt property a couple of months ago that has had a new cable run from the pole to a new BT socket - currently under investigation by TalkTalk, but also experiencing intermittent phone failure.

Anyway having fitted a TalkTalk supplied iplate and new microfilter because BT only fit a single pair these days so cannot fit an ADSL filtered faceplate, decided to check the System Log after the router reset and came across a lot of entries that I've never seen before.

The log only shows one IPv4 assigned address even though I wired up prior to the router resetting - the DHCPINFORM should be showing one for the Ethernet and Wireless as I haven't disabled it while wired and rarely do because I keep forgetting, although it does show that I logged into the router while wired.

An ipconfig /all shows the .102 for Wireless and .100 for Ethernet which the DHCP Table lease confirms.

IPv6 is default unchecked in the router and for both Ethernet and Wireless adapters TCP/IP Properties.

I don't know why it still lists Google's DNS servers when both the router and laptop are set to Open DNS, but I've noticed that when changing the router back to auto DNS they pop up in the Primary and Secondary boxes after Apply until the router has rebooted.

I was once using those but had reverted to auto a while back and have been recently using TalkTalk's own actual DNS severs to the auto ones until they appeared to fail - which is why they are now set to Open DNS.

Anyway enough of the ramble and here is the log to see what you make of it -

Jan 01 00:00:11 syslog syslogd started:
Jan 01 00:00:11 user syslog: klogd &
Jan 01 00:00:11 user kernel: klogd started:
Jan 01 00:00:11 user kernel: OS #1 Wed Jan 2 11:39:17 CST 2013
Jan 01 00:00:11 user kernel: Parallel flash device: name MX29LV320AB, id 0x22a8, size 4096KB
Jan 01 00:00:11 user kernel: CPU revision is: 0002a010
Jan 01 00:00:11 user kernel: Dentry cache hash table entries: 8192 (order: 3, 32768 bytes)
Jan 01 00:00:11 user kernel: Inode-cache hash table entries: 4096 (order: 2, 16384 bytes)
Jan 01 00:00:11 user kernel: Memory: 29768k/32384k available (1757k kernel code, 2572k reserved, 234k data, 76k init, 0k highmem)
Jan 01 00:00:11 user kernel: Total Flash size: 4096K with 71 sectors
Jan 01 00:00:11 user kernel: MPPE/MPPC encryption/compression module registered
Jan 01 00:00:11 user kernel: IP: routing cache hash table of 512 buckets, 4Kbytes
Jan 01 00:00:11 user kernel: TCP: Hash tables configured (established 2048 bind 4096)
Jan 01 00:00:11 user kernel: Initializing IPsec netlink socket
Jan 01 00:00:11 user kernel: 6WIND/LSIIT IPv6 multicast forwarding 0.1 plus PIM-SM/SSM with *BSD API
Jan 01 00:00:11 user kernel: IPv6 over IPv4 tunneling driver
Jan 01 00:00:11 user kernel: VFS: Mounted root (squashfs filesystem) readonly.
Jan 01 00:00:11 user kernel: Freeing unused kernel memory: 76k freed
Jan 01 00:00:11 user kernel: Algorithmics/MIPS FPU Emulator v1.5
Jan 01 00:00:11 user kernel: atmapi: module license 'Proprietary' taints kernel.
Jan 01 00:00:11 user kernel: adsl: adsl_init entry
Jan 01 00:00:11 user kernel: Config Internal PHY Through MDIO
Jan 01 00:00:11 user kernel: ENET: Auto-negotiation timed-out
Jan 01 00:00:11 user kernel: ENET: 10 MB Half-Duplex (assumed)
Jan 01 00:00:11 user kernel: eth0: MAC Address: 00:04:ED:DB:22:19
Jan 01 00:00:11 user kernel: Config Ethernet Switch Through MDIO Pseudo PHY Interface
Jan 01 00:00:11 user kernel: ethsw: found bcm5395!
Jan 01 00:00:11 user kernel: dgasp: kerSysRegisterDyingGaspHandler: eth1 registered
Jan 01 00:00:11 user kernel: eth1: MAC Address: 00:04:ED:DB:22:19
Jan 01 00:00:11 user kernel: eth1 Link UP.
Jan 01 00:00:11 user kernel: rt2880_iNIC: falsely claims to have parameter csumoff
Jan 01 00:00:11 user kernel: RT2880iNIC: 802.11n WLAN PCI driver v2.5.1.0 (Feb. 2, 2012)
Jan 01 00:00:11 user kernel: RT2880iNIC: pci dev 0000:00:01.0 (id 1814:0801 rev 00)
Jan 01 00:00:11 user kernel: PCI: Enabling device 0000:00:01.0 (0000 -> 0002)
Jan 01 00:00:11 user kernel: rt->regs = b0100000
Jan 01 00:00:11 user kernel: Update MAC(0)=00:04:ed:18:fd:b1
Jan 01 00:00:11 user kernel: ============= Init Thread ===================
Jan 01 00:00:11 user kernel: RacfgTaskThread pid = 74
Jan 01 00:00:11 user kernel: RacfgBacklogThread pid = 75
Jan 01 00:00:11 user kernel: ra0: Ralink iNIC at 0xb0100000, 00:04:ed:18:fd:b1, IRQ 39
Jan 01 00:00:11 user kernel: PCI: Setting latency timer of device 0000:00:01.0 to 64
Jan 01 00:00:11 daemon dnsmasq[90]: using nameserver 8.8.4.4#53
Jan 01 00:00:11 daemon dnsmasq[90]: using nameserver 8.8.8.8#53
Jan 01 00:00:11 user kernel: BcmAdsl_Initialize=0xC006F7D8, g_pFnNotifyCallback=0xC0091A04
Jan 01 00:00:12 user kernel: pSdramPHY=0xA1FFFFF8, 0x1B779F 0xDEADBEEF
Jan 01 00:00:12 user kernel: AdslCoreSharedMemInit: shareMemAvailable=19296
Jan 01 00:00:12 user kernel: AdslCoreHwReset: AdslOemDataAddr = 0xA1FF02DC
Jan 01 00:00:12 user kernel: dgasp: kerSysRegisterDyingGaspHandler: dsl0 registered
Jan 01 00:00:12 user kernel: ATM proc init !!!
Jan 01 00:00:12 user kernel: KLOB extended to 2 pools
Jan 01 00:00:14 user kernel: Line 0: xDSL G.994 training
Jan 01 00:00:14 user kernel: BRCM NAT Caching v0.1 Jul 3 2007 10:16:19
Jan 01 00:00:14 user kernel: BRCM NAT Cache: Hooking hit function @ c006cc48
Jan 01 00:00:17 user kernel: ip6_tables: (C) 2000-2002 Netfilter core team
Jan 01 00:00:18 user kernel: ip6_conntrack version 0.1 (253 buckets, 2024 max) - 208 bytes per conntrack
Jan 01 00:00:20 user syslog: ifconfig eth0 up
Jan 01 00:00:20 user syslog: ifconfig br0 192.168.1.254 netmask 255.255.255.0 broadcast 192.168.1.255 up
Jan 01 00:00:20 user syslog: ifconfig eth0 up 2>/dev/null
Jan 01 00:00:20 user syslog: brctl addif br0 eth0 2>/dev/null
Jan 01 00:00:20 user kernel: device eth0 entered promiscuous mode
Jan 01 00:00:20 user kernel: br0: port 1(eth0) entering learning state
Jan 01 00:00:20 user kernel: br0: topology change detected, propagating
Jan 01 00:00:20 user kernel: br0: port 1(eth0) entering forwarding state
Jan 01 00:00:21 user syslog: ifconfig eth1 up
Jan 01 00:00:21 user syslog: ifconfig eth1 up 2>/dev/null
Jan 01 00:00:21 user syslog: brctl addif br0 eth1 2>/dev/null
Jan 01 00:00:21 user kernel: device eth1 entered promiscuous mode
Jan 01 00:00:21 user kernel: br0: port 2(eth1) entering learning state
Jan 01 00:00:21 user kernel: br0: topology change detected, propagating
Jan 01 00:00:21 user kernel: br0: port 2(eth1) entering forwarding state
Jan 01 00:00:21 user kernel: br0: port 1(eth0) entering disabled state
Jan 01 00:00:22 user kernel: Line 0: ADSL G.992 started
Jan 01 00:00:25 user syslog: wps_btn&
Jan 01 00:00:25 user syslog: WSCScan&
Jan 01 00:00:26 user kernel: iNIC Open ra0
Jan 01 00:00:26 user kernel: KLOB extended to 3 pools
Jan 01 00:00:26 user kernel: ADDR0 = 10000008, ADDR1 = 10100008
Jan 01 00:00:26 user kernel: CMD = 0016, STATUS = 04a0
Jan 01 00:00:26 user kernel: LATENCY = 40, CACHE LINE SIZE = 08
Jan 01 00:00:26 user kernel: INT LINE = 39
Jan 01 00:00:26 user kernel: Reset PCI Card
Jan 01 00:00:26 user kernel: ADDR0 = 10000008, ADDR1 = 10100008
Jan 01 00:00:26 user kernel: CMD = 0016, STATUS = 04a0
Jan 01 00:00:26 user kernel: INT LINE = 39
Jan 01 00:00:26 user kernel: ### LATENCY = 20, CACHE LINE SIZE = 08
Jan 01 00:00:26 user kernel: PDMA_RST_IDX = 0
Jan 01 00:00:26 user kernel: PDMA_GLO_CFG = 00000020
Jan 01 00:00:26 user kernel: TX_MAX_CNT0 = 00000080
Jan 01 00:00:26 user kernel: 2. reg = 00000020
Jan 01 00:00:26 user kernel: 2. PDMA_GLO_CFG = 00000065, reg = 00000065
Jan 01 00:00:26 user kernel: Op mode = 1
Jan 01 00:00:26 user kernel: BssidNum=1
Jan 01 00:00:26 user kernel: Wait for boot done...
Jan 01 00:00:26 user kernel: RACFG_CMD_BOOT_NOTIFY
Jan 01 00:00:26 user kernel: Open file: /etc/Wireless/RT2880/iNIC_ap.bin
Jan 01 00:00:26 user kernel: Open file: /var/iNIC_ap.dat
Jan 01 00:00:26 user kernel: RACFG_CMD_BOOT_INITCFG(0)
Jan 01 00:00:26 user kernel: RACFG_CMD_BOOT_INITCFG(1)
Jan 01 00:00:26 user kernel: RACFG_CMD_BOOT_INITCFG(2)
Jan 01 00:00:26 user kernel: Send Init Cfg Data Done(3 packets)
Jan 01 00:00:26 user kernel: RACFG_CMD_BOOT_UPLOAD(0)
Jan 01 00:00:26 user kernel: RACFG_CMD_BOOT_UPLOAD(1)
Jan 01 00:00:26 user kernel: RACFG_CMD_BOOT_UPLOAD(2)
Jan 01 00:00:27 user kernel: Line 0: ADSL G.992 channel analysis
Jan 01 00:00:27 user kernel:
Jan 01 00:00:27 user kernel: CRC:01 08 14 18 f3 ba d7 75 22 32 2e 35 2e 30 2e 31 22 00 00 00 32 30 31 32 30 33 30 38 00 00 00 00 00 00 00 00 f0 45 06 00
Jan 01 00:00:27 user kernel: Send RT2880iNIC Firmware Done
Jan 01 00:00:27 user kernel: ===================================
Jan 01 00:00:27 user kernel: version: "2.5.0.1"
Jan 01 00:00:27 user kernel: size: 411120 bytes
Jan 01 00:00:27 user kernel: date: 20120308
Jan 01 00:00:27 user kernel: ===================================
Jan 01 00:00:27 user kernel:
Jan 01 00:00:27 user kernel: Send STARTUP to RT2880iNIC
Jan 01 00:00:27 user kernel: Close Firmware file
Jan 01 00:00:27 user kernel: RACFG_CMD_BOOT_STARTUP
Jan 01 00:00:29 user kernel: Update MAC(0)=00:04:ed:18:fd:b1
Jan 01 00:00:29 user syslog: ifconfig ra0 up 2>/dev/null
Jan 01 00:00:29 user syslog: brctl addif br0 ra0 2>/dev/null
Jan 01 00:00:29 user kernel: device ra0 entered promiscuous mode
Jan 01 00:00:29 user kernel: br0: port 3(ra0) entering learning state
Jan 01 00:00:29 user kernel: br0: topology change detected, propagating
Jan 01 00:00:29 user kernel: br0: port 3(ra0) entering forwarding state
Jan 01 00:00:30 user syslog: updateDNS -i ppp_0_0_38_1 -n 1 -p 208.67.222.222 -s 208.67.220.220 -T 1
Jan 01 00:00:30 daemon dnsmasq[90]: using nameserver 208.67.220.220#53
Jan 01 00:00:30 daemon dnsmasq[90]: using nameserver 208.67.222.222#53
Jan 01 00:00:30 user syslog: ethctl eth0 vport query 2>/var/vcfgerr
Jan 01 00:00:30 user syslog: rm /var/vcfgerr
Jan 01 00:00:30 user syslog: ethctl eth1 vport query 2>/var/vcfgerr
Jan 01 00:00:30 user syslog: rm /var/vcfgerr
Jan 01 00:00:30 user syslog: rmmod vnet 2>/dev/null
Jan 01 00:00:30 user kernel: br0: port 3(ra0) entering disabled state
Jan 01 00:00:30 user kernel: br0: port 2(eth1) entering disabled state
Jan 01 00:00:30 user kernel: br0: port 3(ra0) entering learning state
Jan 01 00:00:30 user kernel: br0: port 2(eth1) entering learning state
Jan 01 00:00:30 user kernel: br0: topology change detected, propagating
Jan 01 00:00:30 user kernel: br0: port 3(ra0) entering forwarding state
Jan 01 00:00:30 user kernel: br0: topology change detected, propagating
Jan 01 00:00:30 user kernel: br0: port 2(eth1) entering forwarding state
Jan 01 00:00:30 user kernel: br0: port 1(eth0) entering learning state
Jan 01 00:00:30 user kernel: br0: topology change detected, propagating
Jan 01 00:00:30 user kernel: br0: port 1(eth0) entering forwarding state
Jan 01 00:00:32 daemon dnsmasq[90]: using nameserver 208.67.220.220#53
Jan 01 00:00:32 daemon dnsmasq[90]: using nameserver 208.67.222.222#53
Jan 01 00:00:32 daemon UPNPD[534]: HTTP listening on port 2800
Jan 01 00:00:33 user kernel: Line 0: ADSL G.992 message exchange
Jan 01 00:00:33 daemon pppd[545]: PPPoATM setdevname_pppoatm
Jan 01 00:00:33 daemon pppd[545]: PPPoATM setdevname_pppoatm - SUCCESS
Jan 01 00:00:33 daemon dnsmasq[90]: using nameserver 208.67.220.220#53
Jan 01 00:00:33 daemon dnsmasq[90]: using nameserver 208.67.222.222#53
Jan 01 00:00:33 daemon pppd[545]: pppd 2.4.1 started by admin, uid 0
Jan 01 00:00:33 user kernel: br0: port 1(eth0) entering disabled state
Jan 01 00:00:34 user kernel: Line 0: ADSL link down
Jan 01 00:00:39 user kernel: Line 0: xDSL G.994 training
Jan 01 00:00:40 daemon DHCP SERVER: DHCP request from dc:0e:a1:35:68:e1
Jan 01 00:00:40 daemon DHCP SERVER: DHCP ack to dc:0e:a1:35:68:e1
Jan 01 00:00:44 daemon DHCP SERVER: DHCPINFORM from 192.168.1.100
Jan 01 00:00:47 user kernel: Line 0: ADSL G.992 started
Jan 01 00:00:47 daemon DHCP SERVER: DHCPINFORM from 192.168.1.100
Jan 01 00:00:52 user kernel: Line 0: ADSL G.992 channel analysis
Jan 01 00:00:56 user syslog: web: ::ffff:192.168.1.100 login
Jan 01 00:00:58 user kernel: Line 0: ADSL G.992 message exchange
Jan 01 00:00:58 user kernel: Line 0: ADSL link up, Path 0, us=893, ds=5966
Jan 01 00:01:00 daemon pppd[545]: PPPoE: Terminating on signal 15.
Jan 01 00:01:00 daemon pppd[545]: Exit.
Jan 01 00:01:00 daemon pppd[850]: PPPoATM setdevname_pppoatm
Jan 01 00:01:00 daemon pppd[850]: PPPoATM setdevname_pppoatm - SUCCESS
Jan 01 00:01:00 daemon pppd[850]: pppd 2.4.1 started by admin, uid 0
Jan 01 00:01:01 daemon pppd[850]: PPP: Start to connect ...
Jan 01 00:01:01 daemon pppd[850]: Using interface ppp0_0_38_1
Jan 01 00:01:01 daemon pppd[850]: Connect: ppp_0_0_38_1 <-->
Jan 01 00:01:01 daemon pppd[850]: Couldn't increase MTU to 1500.
Jan 01 00:01:04 daemon pppd[850]: PPP LCP UP.
Jan 01 00:01:05 daemon pppd[850]: Remote message: CHAP authentication success, unit 28576
Jan 01 00:01:05 daemon pppd[850]: local IP address 92.23.135.121
Jan 01 00:01:05 daemon pppd[850]: remote IP address 92.23.128.1
Jan 01 00:01:05 daemon pppd[850]: primary DNS address 62.24.243.4
Jan 01 00:01:05 daemon pppd[850]: secondary DNS address 62.24.202.70
Jan 01 00:01:05 daemon pppd[850]: Received valid IP address from server. Connection UP.
Jan 01 00:01:05 user kernel: KLOB extended to 4 pools
Jan 01 00:01:05 user syslog: begin: interface: ppp_0_0_38_1 go to up
Jan 01 00:01:05 daemon dnsmasq[90]: using nameserver 208.67.220.220#53
Jan 01 00:01:05 daemon dnsmasq[90]: using nameserver 208.67.222.222#53
Jan 01 00:01:05 daemon UPNPD[534]: received signal 15, good-bye
Jan 01 00:01:07 daemon UPNPD[961]: HTTP listening on port 2800
Jan 01 00:01:09 user syslog: end: interface: ppp_0_0_38_1 go to up
Jan 01 00:01:16 daemon DHCP SERVER: DHCP request from 74:de:2b:b1:b9:f7
Jan 01 00:01:16 daemon DHCP SERVER: DHCP ack to 74:de:2b:b1:b9:f7
Jan 01 00:01:19 daemon DHCP SERVER: DHCPINFORM from 192.168.1.102
Jan 01 00:01:23 daemon DHCP SERVER: DHCPINFORM from 192.168.1.102
Top
billion_fan
Posts: 5398
Joined: Tue Jul 19, 2011 4:30 pm

Re: System Log Puzzler

Post by billion_fan »

Tomken wrote:Hi billion_fan, - The background -

Not really getting the sync speeds I'm used to getting having moved back into a rebuilt property a couple of months ago that has had a new cable run from the pole to a new BT socket - currently under investigation by TalkTalk, but also experiencing intermittent phone failure.

Anyway having fitted a TalkTalk supplied iplate and new microfilter because BT only fit a single pair these days so cannot fit an ADSL filtered faceplate, decided to check the System Log after the router reset and came across a lot of entries that I've never seen before.

The log only shows one IPv4 assigned address even though I wired up prior to the router resetting - the DHCPINFORM should be showing one for the Ethernet and Wireless as I haven't disabled it while wired and rarely do because I keep forgetting, although it does show that I logged into the router while wired.

An ipconfig /all shows the .102 for Wireless and .100 for Ethernet which the DHCP Table lease confirms.

IPv6 is default unchecked in the router and for both Ethernet and Wireless adapters TCP/IP Properties.

I don't know why it still lists Google's DNS servers when both the router and laptop are set to Open DNS, but I've noticed that when changing the router back to auto DNS they pop up in the Primary and Secondary boxes after Apply until the router has rebooted.

I was once using those but had reverted to auto a while back and have been recently using TalkTalk's own actual DNS severs to the auto ones until they appeared to fail - which is why they are now set to Open DNS.

Anyway enough of the ramble and here is the log to see what you make of it -

Jan 01 00:00:11 syslog syslogd started:
Jan 01 00:00:11 user syslog: klogd &
Jan 01 00:00:11 user kernel: klogd started:
Jan 01 00:00:11 user kernel: OS #1 Wed Jan 2 11:39:17 CST 2013
Jan 01 00:00:11 user kernel: Parallel flash device: name MX29LV320AB, id 0x22a8, size 4096KB
Jan 01 00:00:11 user kernel: CPU revision is: 0002a010
Jan 01 00:00:11 user kernel: Dentry cache hash table entries: 8192 (order: 3, 32768 bytes)
Jan 01 00:00:11 user kernel: Inode-cache hash table entries: 4096 (order: 2, 16384 bytes)
Jan 01 00:00:11 user kernel: Memory: 29768k/32384k available (1757k kernel code, 2572k reserved, 234k data, 76k init, 0k highmem)
Jan 01 00:00:11 user kernel: Total Flash size: 4096K with 71 sectors
Jan 01 00:00:11 user kernel: MPPE/MPPC encryption/compression module registered
Jan 01 00:00:11 user kernel: IP: routing cache hash table of 512 buckets, 4Kbytes
Jan 01 00:00:11 user kernel: TCP: Hash tables configured (established 2048 bind 4096)
Jan 01 00:00:11 user kernel: Initializing IPsec netlink socket
Jan 01 00:00:11 user kernel: 6WIND/LSIIT IPv6 multicast forwarding 0.1 plus PIM-SM/SSM with *BSD API
Jan 01 00:00:11 user kernel: IPv6 over IPv4 tunneling driver
Jan 01 00:00:11 user kernel: VFS: Mounted root (squashfs filesystem) readonly.
Jan 01 00:00:11 user kernel: Freeing unused kernel memory: 76k freed
Jan 01 00:00:11 user kernel: Algorithmics/MIPS FPU Emulator v1.5
Jan 01 00:00:11 user kernel: atmapi: module license 'Proprietary' taints kernel.
Jan 01 00:00:11 user kernel: adsl: adsl_init entry
Jan 01 00:00:11 user kernel: Config Internal PHY Through MDIO
Jan 01 00:00:11 user kernel: ENET: Auto-negotiation timed-out
Jan 01 00:00:11 user kernel: ENET: 10 MB Half-Duplex (assumed)
Jan 01 00:00:11 user kernel: eth0: MAC Address: 00:04:ED:DB:22:19
Jan 01 00:00:11 user kernel: Config Ethernet Switch Through MDIO Pseudo PHY Interface
Jan 01 00:00:11 user kernel: ethsw: found bcm5395!
Jan 01 00:00:11 user kernel: dgasp: kerSysRegisterDyingGaspHandler: eth1 registered
Jan 01 00:00:11 user kernel: eth1: MAC Address: 00:04:ED:DB:22:19
Jan 01 00:00:11 user kernel: eth1 Link UP.
Jan 01 00:00:11 user kernel: rt2880_iNIC: falsely claims to have parameter csumoff
Jan 01 00:00:11 user kernel: RT2880iNIC: 802.11n WLAN PCI driver v2.5.1.0 (Feb. 2, 2012)
Jan 01 00:00:11 user kernel: RT2880iNIC: pci dev 0000:00:01.0 (id 1814:0801 rev 00)
Jan 01 00:00:11 user kernel: PCI: Enabling device 0000:00:01.0 (0000 -> 0002)
Jan 01 00:00:11 user kernel: rt->regs = b0100000
Jan 01 00:00:11 user kernel: Update MAC(0)=00:04:ed:18:fd:b1
Jan 01 00:00:11 user kernel: ============= Init Thread ===================
Jan 01 00:00:11 user kernel: RacfgTaskThread pid = 74
Jan 01 00:00:11 user kernel: RacfgBacklogThread pid = 75
Jan 01 00:00:11 user kernel: ra0: Ralink iNIC at 0xb0100000, 00:04:ed:18:fd:b1, IRQ 39
Jan 01 00:00:11 user kernel: PCI: Setting latency timer of device 0000:00:01.0 to 64
Jan 01 00:00:11 daemon dnsmasq[90]: using nameserver 8.8.4.4#53
Jan 01 00:00:11 daemon dnsmasq[90]: using nameserver 8.8.8.8#53
Jan 01 00:00:11 user kernel: BcmAdsl_Initialize=0xC006F7D8, g_pFnNotifyCallback=0xC0091A04
Jan 01 00:00:12 user kernel: pSdramPHY=0xA1FFFFF8, 0x1B779F 0xDEADBEEF
Jan 01 00:00:12 user kernel: AdslCoreSharedMemInit: shareMemAvailable=19296
Jan 01 00:00:12 user kernel: AdslCoreHwReset: AdslOemDataAddr = 0xA1FF02DC
Jan 01 00:00:12 user kernel: dgasp: kerSysRegisterDyingGaspHandler: dsl0 registered
Jan 01 00:00:12 user kernel: ATM proc init !!!
Jan 01 00:00:12 user kernel: KLOB extended to 2 pools
Jan 01 00:00:14 user kernel: Line 0: xDSL G.994 training
Jan 01 00:00:14 user kernel: BRCM NAT Caching v0.1 Jul 3 2007 10:16:19
Jan 01 00:00:14 user kernel: BRCM NAT Cache: Hooking hit function @ c006cc48
Jan 01 00:00:17 user kernel: ip6_tables: (C) 2000-2002 Netfilter core team
Jan 01 00:00:18 user kernel: ip6_conntrack version 0.1 (253 buckets, 2024 max) - 208 bytes per conntrack
Jan 01 00:00:20 user syslog: ifconfig eth0 up
Jan 01 00:00:20 user syslog: ifconfig br0 192.168.1.254 netmask 255.255.255.0 broadcast 192.168.1.255 up
Jan 01 00:00:20 user syslog: ifconfig eth0 up 2>/dev/null
Jan 01 00:00:20 user syslog: brctl addif br0 eth0 2>/dev/null
Jan 01 00:00:20 user kernel: device eth0 entered promiscuous mode
Jan 01 00:00:20 user kernel: br0: port 1(eth0) entering learning state
Jan 01 00:00:20 user kernel: br0: topology change detected, propagating
Jan 01 00:00:20 user kernel: br0: port 1(eth0) entering forwarding state
Jan 01 00:00:21 user syslog: ifconfig eth1 up
Jan 01 00:00:21 user syslog: ifconfig eth1 up 2>/dev/null
Jan 01 00:00:21 user syslog: brctl addif br0 eth1 2>/dev/null
Jan 01 00:00:21 user kernel: device eth1 entered promiscuous mode
Jan 01 00:00:21 user kernel: br0: port 2(eth1) entering learning state
Jan 01 00:00:21 user kernel: br0: topology change detected, propagating
Jan 01 00:00:21 user kernel: br0: port 2(eth1) entering forwarding state
Jan 01 00:00:21 user kernel: br0: port 1(eth0) entering disabled state
Jan 01 00:00:22 user kernel: Line 0: ADSL G.992 started
Jan 01 00:00:25 user syslog: wps_btn&
Jan 01 00:00:25 user syslog: WSCScan&
Jan 01 00:00:26 user kernel: iNIC Open ra0
Jan 01 00:00:26 user kernel: KLOB extended to 3 pools
Jan 01 00:00:26 user kernel: ADDR0 = 10000008, ADDR1 = 10100008
Jan 01 00:00:26 user kernel: CMD = 0016, STATUS = 04a0
Jan 01 00:00:26 user kernel: LATENCY = 40, CACHE LINE SIZE = 08
Jan 01 00:00:26 user kernel: INT LINE = 39
Jan 01 00:00:26 user kernel: Reset PCI Card
Jan 01 00:00:26 user kernel: ADDR0 = 10000008, ADDR1 = 10100008
Jan 01 00:00:26 user kernel: CMD = 0016, STATUS = 04a0
Jan 01 00:00:26 user kernel: INT LINE = 39
Jan 01 00:00:26 user kernel: ### LATENCY = 20, CACHE LINE SIZE = 08
Jan 01 00:00:26 user kernel: PDMA_RST_IDX = 0
Jan 01 00:00:26 user kernel: PDMA_GLO_CFG = 00000020
Jan 01 00:00:26 user kernel: TX_MAX_CNT0 = 00000080
Jan 01 00:00:26 user kernel: 2. reg = 00000020
Jan 01 00:00:26 user kernel: 2. PDMA_GLO_CFG = 00000065, reg = 00000065
Jan 01 00:00:26 user kernel: Op mode = 1
Jan 01 00:00:26 user kernel: BssidNum=1
Jan 01 00:00:26 user kernel: Wait for boot done...
Jan 01 00:00:26 user kernel: RACFG_CMD_BOOT_NOTIFY
Jan 01 00:00:26 user kernel: Open file: /etc/Wireless/RT2880/iNIC_ap.bin
Jan 01 00:00:26 user kernel: Open file: /var/iNIC_ap.dat
Jan 01 00:00:26 user kernel: RACFG_CMD_BOOT_INITCFG(0)
Jan 01 00:00:26 user kernel: RACFG_CMD_BOOT_INITCFG(1)
Jan 01 00:00:26 user kernel: RACFG_CMD_BOOT_INITCFG(2)
Jan 01 00:00:26 user kernel: Send Init Cfg Data Done(3 packets)
Jan 01 00:00:26 user kernel: RACFG_CMD_BOOT_UPLOAD(0)
Jan 01 00:00:26 user kernel: RACFG_CMD_BOOT_UPLOAD(1)
Jan 01 00:00:26 user kernel: RACFG_CMD_BOOT_UPLOAD(2)
Jan 01 00:00:27 user kernel: Line 0: ADSL G.992 channel analysis
Jan 01 00:00:27 user kernel:
Jan 01 00:00:27 user kernel: CRC:01 08 14 18 f3 ba d7 75 22 32 2e 35 2e 30 2e 31 22 00 00 00 32 30 31 32 30 33 30 38 00 00 00 00 00 00 00 00 f0 45 06 00
Jan 01 00:00:27 user kernel: Send RT2880iNIC Firmware Done
Jan 01 00:00:27 user kernel: ===================================
Jan 01 00:00:27 user kernel: version: "2.5.0.1"
Jan 01 00:00:27 user kernel: size: 411120 bytes
Jan 01 00:00:27 user kernel: date: 20120308
Jan 01 00:00:27 user kernel: ===================================
Jan 01 00:00:27 user kernel:
Jan 01 00:00:27 user kernel: Send STARTUP to RT2880iNIC
Jan 01 00:00:27 user kernel: Close Firmware file
Jan 01 00:00:27 user kernel: RACFG_CMD_BOOT_STARTUP
Jan 01 00:00:29 user kernel: Update MAC(0)=00:04:ed:18:fd:b1
Jan 01 00:00:29 user syslog: ifconfig ra0 up 2>/dev/null
Jan 01 00:00:29 user syslog: brctl addif br0 ra0 2>/dev/null
Jan 01 00:00:29 user kernel: device ra0 entered promiscuous mode
Jan 01 00:00:29 user kernel: br0: port 3(ra0) entering learning state
Jan 01 00:00:29 user kernel: br0: topology change detected, propagating
Jan 01 00:00:29 user kernel: br0: port 3(ra0) entering forwarding state
Jan 01 00:00:30 user syslog: updateDNS -i ppp_0_0_38_1 -n 1 -p 208.67.222.222 -s 208.67.220.220 -T 1
Jan 01 00:00:30 daemon dnsmasq[90]: using nameserver 208.67.220.220#53
Jan 01 00:00:30 daemon dnsmasq[90]: using nameserver 208.67.222.222#53
Jan 01 00:00:30 user syslog: ethctl eth0 vport query 2>/var/vcfgerr
Jan 01 00:00:30 user syslog: rm /var/vcfgerr
Jan 01 00:00:30 user syslog: ethctl eth1 vport query 2>/var/vcfgerr
Jan 01 00:00:30 user syslog: rm /var/vcfgerr
Jan 01 00:00:30 user syslog: rmmod vnet 2>/dev/null
Jan 01 00:00:30 user kernel: br0: port 3(ra0) entering disabled state
Jan 01 00:00:30 user kernel: br0: port 2(eth1) entering disabled state
Jan 01 00:00:30 user kernel: br0: port 3(ra0) entering learning state
Jan 01 00:00:30 user kernel: br0: port 2(eth1) entering learning state
Jan 01 00:00:30 user kernel: br0: topology change detected, propagating
Jan 01 00:00:30 user kernel: br0: port 3(ra0) entering forwarding state
Jan 01 00:00:30 user kernel: br0: topology change detected, propagating
Jan 01 00:00:30 user kernel: br0: port 2(eth1) entering forwarding state
Jan 01 00:00:30 user kernel: br0: port 1(eth0) entering learning state
Jan 01 00:00:30 user kernel: br0: topology change detected, propagating
Jan 01 00:00:30 user kernel: br0: port 1(eth0) entering forwarding state
Jan 01 00:00:32 daemon dnsmasq[90]: using nameserver 208.67.220.220#53
Jan 01 00:00:32 daemon dnsmasq[90]: using nameserver 208.67.222.222#53
Jan 01 00:00:32 daemon UPNPD[534]: HTTP listening on port 2800
Jan 01 00:00:33 user kernel: Line 0: ADSL G.992 message exchange
Jan 01 00:00:33 daemon pppd[545]: PPPoATM setdevname_pppoatm
Jan 01 00:00:33 daemon pppd[545]: PPPoATM setdevname_pppoatm - SUCCESS
Jan 01 00:00:33 daemon dnsmasq[90]: using nameserver 208.67.220.220#53
Jan 01 00:00:33 daemon dnsmasq[90]: using nameserver 208.67.222.222#53
Jan 01 00:00:33 daemon pppd[545]: pppd 2.4.1 started by admin, uid 0
Jan 01 00:00:33 user kernel: br0: port 1(eth0) entering disabled state
Jan 01 00:00:34 user kernel: Line 0: ADSL link down
Jan 01 00:00:39 user kernel: Line 0: xDSL G.994 training
Jan 01 00:00:40 daemon DHCP SERVER: DHCP request from dc:0e:a1:35:68:e1
Jan 01 00:00:40 daemon DHCP SERVER: DHCP ack to dc:0e:a1:35:68:e1
Jan 01 00:00:44 daemon DHCP SERVER: DHCPINFORM from 192.168.1.100
Jan 01 00:00:47 user kernel: Line 0: ADSL G.992 started
Jan 01 00:00:47 daemon DHCP SERVER: DHCPINFORM from 192.168.1.100
Jan 01 00:00:52 user kernel: Line 0: ADSL G.992 channel analysis
Jan 01 00:00:56 user syslog: web: ::ffff:192.168.1.100 login
Jan 01 00:00:58 user kernel: Line 0: ADSL G.992 message exchange
Jan 01 00:00:58 user kernel: Line 0: ADSL link up, Path 0, us=893, ds=5966
Jan 01 00:01:00 daemon pppd[545]: PPPoE: Terminating on signal 15.
Jan 01 00:01:00 daemon pppd[545]: Exit.
Jan 01 00:01:00 daemon pppd[850]: PPPoATM setdevname_pppoatm
Jan 01 00:01:00 daemon pppd[850]: PPPoATM setdevname_pppoatm - SUCCESS
Jan 01 00:01:00 daemon pppd[850]: pppd 2.4.1 started by admin, uid 0
Jan 01 00:01:01 daemon pppd[850]: PPP: Start to connect ...
Jan 01 00:01:01 daemon pppd[850]: Using interface ppp0_0_38_1
Jan 01 00:01:01 daemon pppd[850]: Connect: ppp_0_0_38_1 <-->
Jan 01 00:01:01 daemon pppd[850]: Couldn't increase MTU to 1500.
Jan 01 00:01:04 daemon pppd[850]: PPP LCP UP.
Jan 01 00:01:05 daemon pppd[850]: Remote message: CHAP authentication success, unit 28576
Jan 01 00:01:05 daemon pppd[850]: local IP address 92.23.135.121
Jan 01 00:01:05 daemon pppd[850]: remote IP address 92.23.128.1
Jan 01 00:01:05 daemon pppd[850]: primary DNS address 62.24.243.4
Jan 01 00:01:05 daemon pppd[850]: secondary DNS address 62.24.202.70
Jan 01 00:01:05 daemon pppd[850]: Received valid IP address from server. Connection UP.
Jan 01 00:01:05 user kernel: KLOB extended to 4 pools
Jan 01 00:01:05 user syslog: begin: interface: ppp_0_0_38_1 go to up
Jan 01 00:01:05 daemon dnsmasq[90]: using nameserver 208.67.220.220#53
Jan 01 00:01:05 daemon dnsmasq[90]: using nameserver 208.67.222.222#53
Jan 01 00:01:05 daemon UPNPD[534]: received signal 15, good-bye
Jan 01 00:01:07 daemon UPNPD[961]: HTTP listening on port 2800
Jan 01 00:01:09 user syslog: end: interface: ppp_0_0_38_1 go to up
Jan 01 00:01:16 daemon DHCP SERVER: DHCP request from 74:de:2b:b1:b9:f7
Jan 01 00:01:16 daemon DHCP SERVER: DHCP ack to 74:de:2b:b1:b9:f7
Jan 01 00:01:19 daemon DHCP SERVER: DHCPINFORM from 192.168.1.102
Jan 01 00:01:23 daemon DHCP SERVER: DHCPINFORM from 192.168.1.102

The system log looks fine to me, the device that has 192.168.1.100 as a IP address, I assume that this device does not need to renew the IP, so it has not listed this device.

As you have a intermittent phone failure, I would let talktalk investigate and see if they can sovle you issues, once solved the sync rate should go back to normal.
Top
Tomken
Posts: 467
Joined: Tue Jul 26, 2011 10:31 am
Location: Co Durham

Re: System Log Puzzler

Post by Tomken »

Thanks billion_fan.

The .100 is the Ethernet address for this laptop.

The phone failure just occurred the one day and when I phoned up for a sitrep on the broadband fault, I was told that it had been fixed - even though the sync spreed was still down by over a meg.

I rebooted the router this morning when I saw that I had a decent Downstream SNRM - 7.1 on a 6dB Interleaved line and it came back with the best speed bar one I've had since moving back in here, but there are still a lot of errors on the line.

Phoned TalkTalk up on Monday and even though I said I was getting the same results with two routers (7800N and D-Link 2680) they said they would send me out another router to try ??

This Is what Telnet is showing for the line since I rebooted this morning, but not sure why D is showing as 64 when it's normally 32 although D once showed as 16/2 but a reboot restored that to 32/4.

I'm waiting for the power to be shut off sometime this afternoon while the leccy board are doing some work, so I'll see what the 7800N comes back with afterwards.

Login: admin
Password:
> adsl info --stats
adsl: ADSL driver and PHY status
Status: Showtime
Retrain Reason: 8000
Max: Upstream rate = 884 Kbps, Downstream rate = 6244 Kbps
Path: 0, Upstream rate = 870 Kbps, Downstream rate = 6137 Kbps

Link Power State: L0
Mode: ADSL2+
TPS-TC: ATM Mode
Trellis: U:ON /D:ON
Line Status: No Defect
Training Status: Showtime
Down Up
SNR (dB): 2.3 6.1
Attn(dB): 50.0 27.2
Pwr(dBm): 0.0 12.9
ADSL2 framing
MSGc: 63 10
B: 59 40
M: 4 4
T: 3 3
R: 14 8
S: 1.2443 5.9826
L: 1633 230
D: 64 4
Counters
SF: 1103769 55274
SFErr: 59523 56
RS: 57120050 3279847
RSCorr: 25925659 718
RSUnCorr: 74013 0

HEC: 41144 56
OCD: 0 0
LCD: 0 0
Total Cells: 257158302 36379259
Data Cells: 359508 71629
Drop Cells: 0
Bit Errors: 0 4879

ES: 7985 37
SES: 205 0
UAS: 34 34
AS: 17770

INP: 2.19 0.55
PER: 16.09 17.94
delay: 19.90 5.98
OR: 34.28 7.13

Bitswap: 2589 91

Total time = 4 hours 56 min 56 sec
FEC: 25925659 718
CRC: 59523 56
ES: 7985 37
SES: 205 0
UAS: 34 34
LOS: 0 0
LOF: 0 0
Latest 15 minutes time = 11 min 56 sec
FEC: 2150319 0
CRC: 6323 0
ES: 683 0
SES: 1 0
UAS: 0 0
LOS: 0 0
LOF: 0 0
Previous 15 minutes time = 15 min 0 sec
FEC: 2682822 0
CRC: 5269 0
ES: 828 0
SES: 4 0
UAS: 0 0
LOS: 0 0
LOF: 0 0
Latest 1 day time = 4 hours 56 min 56 sec
FEC: 25925659 718
CRC: 59523 56
ES: 7985 37
SES: 205 0
UAS: 34 34
LOS: 0 0
LOF: 0 0
Previous 1 day time = 0 sec
FEC: 0 0
CRC: 0 0
ES: 0 0
SES: 0 0
UAS: 0 0
LOS: 0 0
LOF: 0 0
Since Link time = 4 hours 56 min 9 sec
FEC: 25925659 718
CRC: 59523 56
ES: 7985 37
SES: 205 0
UAS: 0 0
LOS: 0 0
LOF: 0 0
>
Top
Post Reply

Return to “7800/7800N/7800GZ”