[OpenWrt-Devel] WAN bouncing at boot

Weedy weedy2887 at gmail.com
Fri Oct 3 12:25:21 EDT 2014


On Tue, Aug 12, 2014 at 10:05 AM, Bas Mevissen <abuse at basmevissen.nl> wrote:
>
>
> On 08/09/2014 04:13 AM, Weedy wrote:
>> On Sun, Jul 27, 2014 at 3:31 PM, Weedy <weedy2887 at gmail.com> wrote:
>>> Is there anything I can do to stop this? It started sometime in the
>>> last 6months of trunk.
>>> Right after this and couple minutes after boot my healing script fires
>>> and detects that WAN is broken and calls ifdown; sleep; ifup at which
>>> point I get an IP and keep it. But why it the WAN goinig up and down
>>> during boot?
>>>
>
> Difficult to help you without any information about the platform.
>
> You might go back in time and track down the change that caused the
> issue by bisection. Can take some time to execute, but is feasible when
> the problem is reproducible. Beware that when going back in time with
> the sources, you must force recompilation.

TP-Link 4300 on trunk. It only bounces at boot. I got 5 or 6
distcleans into it and it's just so disruptive. I would be nice to
have a hint.

Thu Oct  2 19:48:33 2014 kern.info kernel: [    0.610000] switch0:
Atheros AR8327 rev. 2 switch registered on ag71xx-mdio.0
Thu Oct  2 19:48:33 2014 kern.info kernel: [    1.840000] libphy:
ag71xx_mdio: probed
Thu Oct  2 19:48:33 2014 kern.info kernel: [    2.390000] ag71xx
ag71xx.0: connected to PHY at ag71xx-mdio.0:00 [uid=004dd033,
driver=Atheros AR8216/AR8236/AR8316]
Thu Oct  2 19:48:33 2014 kern.info kernel: [    2.400000] eth0:
Atheros AG71xx at 0xb9000000, irq 4, mode:RGMII
Thu Oct  2 19:48:33 2014 kern.info kernel: [    2.410000] TCP: cubic registered
Thu Oct  2 19:48:33 2014 kern.info kernel: [    2.410000] NET:
Registered protocol family 17
Thu Oct  2 19:48:33 2014 kern.info kernel: [    2.420000] 8021q:
802.1Q VLAN Support v1.8
Thu Oct  2 19:48:33 2014 kern.info kernel: [    2.430000] VFS: Mounted
root (squashfs filesystem) readonly on device 31:2.
Thu Oct  2 19:48:33 2014 kern.info kernel: [    2.440000] Freeing
unused kernel memory: 284K (80329000 - 80370000)
Thu Oct  2 19:48:33 2014 kern.info kernel: [    4.740000] usbcore:
registered new interface driver usbfs
Thu Oct  2 19:48:33 2014 kern.info kernel: [    4.750000] usbcore:
registered new interface driver hub
Thu Oct  2 19:48:33 2014 kern.info kernel: [    4.760000] usbcore:
registered new device driver usb
Thu Oct  2 19:48:33 2014 kern.info kernel: [    4.770000] ehci_hcd:
USB 2.0 'Enhanced' Host Controller (EHCI) Driver
Thu Oct  2 19:48:33 2014 kern.info kernel: [    4.770000]
ehci-platform: EHCI generic platform driver
Thu Oct  2 19:48:33 2014 kern.info kernel: [    4.780000]
ehci-platform ehci-platform: EHCI Host Controller
Thu Oct  2 19:48:33 2014 kern.info kernel: [    4.780000]
ehci-platform ehci-platform: new USB bus registered, assigned bus
number 1
Thu Oct  2 19:48:33 2014 kern.info kernel: [    4.790000]
ehci-platform ehci-platform: irq 3, io mem 0x1b000000
Thu Oct  2 19:48:33 2014 kern.info kernel: [    4.820000]
ehci-platform ehci-platform: USB 2.0 started, EHCI 1.00
Thu Oct  2 19:48:33 2014 kern.info kernel: [    4.820000] hub 1-0:1.0:
USB hub found
Thu Oct  2 19:48:33 2014 kern.info kernel: [    4.830000] hub 1-0:1.0:
1 port detected
Thu Oct  2 19:48:33 2014 kern.info kernel: [    5.330000] usb 1-1: new
high-speed USB device number 2 using ehci-platform
Thu Oct  2 19:48:33 2014 kern.info kernel: [    5.480000] hub 1-1:1.0:
USB hub found
Thu Oct  2 19:48:33 2014 kern.info kernel: [    5.480000] hub 1-1:1.0:
4 ports detected
Thu Oct  2 19:48:33 2014 kern.info kernel: [    6.410000] eth0: link
up (1000Mbps/Full duplex)
Thu Oct  2 19:48:33 2014 kern.info kernel: [    8.650000] eth0: link down
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.350000] NET:
Registered protocol family 10
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.370000] ip6_tables:
(C) 2000-2006 Netfilter Core Team
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.410000] u32 classifier
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.410000]     input
device check on
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.410000]     Actions configured
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.420000]
Mirror/redirect action on
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.440000] nf_conntrack
version 0.5.0 (1976 buckets, 7904 max)
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.470000] Loading
modules backported from Linux version master-2014-09-26-0-g25e3efa
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.470000] Backport
generated by backports.git backports-20140905-1-gde42785
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.490000] ip_tables:
(C) 2000-2006 Netfilter Core Team
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.630000] xt_time:
kernel timezone is -0000
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.660000] cfg80211:
Calling CRDA to update world regulatory domain
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.660000] cfg80211:
World regulatory domain updated:
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.670000] cfg80211:
DFS Master region: unset
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.670000] cfg80211:
(start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp),
(dfs_cac_time)
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.680000] cfg80211:
(2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.690000] cfg80211:
(2457000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.700000] cfg80211:
(2474000 KHz - 2494000 KHz @ 20000 KHz), (N/A, 2000 mBm), (N/A)
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.710000] cfg80211:
(5170000 KHz - 5250000 KHz @ 160000 KHz), (N/A, 2000 mBm), (N/A)
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.710000] cfg80211:
(5250000 KHz - 5330000 KHz @ 160000 KHz), (N/A, 2000 mBm), (0 s)
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.720000] cfg80211:
(5490000 KHz - 5730000 KHz @ 160000 KHz), (N/A, 2000 mBm), (0 s)
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.730000] cfg80211:
(5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 2000 mBm), (N/A)
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.740000] cfg80211:
(57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 0 mBm), (N/A)
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.820000] PPP generic
driver version 2.4.2
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.820000] NET:
Registered protocol family 24
Thu Oct  2 19:48:33 2014 kern.debug kernel: [   10.870000] ath: EEPROM
regdomain: 0x0
Thu Oct  2 19:48:33 2014 kern.debug kernel: [   10.870000] ath: EEPROM
indicates default country code should be used
Thu Oct  2 19:48:33 2014 kern.debug kernel: [   10.870000] ath: doing
EEPROM country->regdmn map search
Thu Oct  2 19:48:33 2014 kern.debug kernel: [   10.870000] ath:
country maps to regdmn code: 0x3a
Thu Oct  2 19:48:33 2014 kern.debug kernel: [   10.870000] ath:
Country alpha2 being used: US
Thu Oct  2 19:48:33 2014 kern.debug kernel: [   10.870000] ath:
Regpair used: 0x3a
Thu Oct  2 19:48:33 2014 kern.debug kernel: [   10.880000] ieee80211
phy0: Selected rate control algorithm 'minstrel_ht'
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.890000] ieee80211
phy0: Atheros AR9340 Rev:0 mem=0xb8100000, irq=47
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.900000] cfg80211:
Calling CRDA for country: US
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.900000] cfg80211:
Regulatory domain changed to country: US
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.910000] cfg80211:
DFS Master region: FCC
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.910000] cfg80211:
(start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp),
(dfs_cac_time)
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.920000] cfg80211:
(2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 3000 mBm), (N/A)
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.930000] cfg80211:
(5170000 KHz - 5250000 KHz @ 80000 KHz), (N/A, 1700 mBm), (N/A)
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.940000] cfg80211:
(5250000 KHz - 5330000 KHz @ 80000 KHz), (N/A, 2300 mBm), (0 s)
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.950000] cfg80211:
(5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 3000 mBm), (N/A)
Thu Oct  2 19:48:33 2014 kern.info kernel: [   10.950000] cfg80211:
(57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 4000 mBm), (N/A)
Thu Oct  2 19:48:33 2014 kern.warn kernel: [   10.960000] PCI:
Enabling device 0000:00:00.0 (0000 -> 0002)
Thu Oct  2 19:48:33 2014 kern.debug kernel: [   10.970000] ath: EEPROM
regdomain: 0x0
Thu Oct  2 19:48:33 2014 kern.debug kernel: [   10.970000] ath: EEPROM
indicates default country code should be used
Thu Oct  2 19:48:33 2014 kern.debug kernel: [   10.970000] ath: doing
EEPROM country->regdmn map search
Thu Oct  2 19:48:33 2014 kern.debug kernel: [   10.970000] ath:
country maps to regdmn code: 0x3a
Thu Oct  2 19:48:33 2014 kern.debug kernel: [   10.970000] ath:
Country alpha2 being used: US
Thu Oct  2 19:48:33 2014 kern.debug kernel: [   10.970000] ath:
Regpair used: 0x3a
Thu Oct  2 19:48:33 2014 kern.debug kernel: [   11.000000] ieee80211
phy1: Selected rate control algorithm 'minstrel_ht'
Thu Oct  2 19:48:33 2014 kern.info kernel: [   11.030000] ieee80211
phy1: Atheros AR9300 Rev:4 mem=0xb0000000, irq=40
Thu Oct  2 19:48:35 2014 cron.info crond[966]: crond: crond (busybox
1.22.1) started, log level 5
Thu Oct  2 19:48:36 2014 authpriv.warn dropbear[987]: Failed loading
/etc/dropbear/dropbear_ecdsa_host_key
Thu Oct  2 19:48:36 2014 authpriv.info dropbear[987]: Not backgrounding
Thu Oct  2 19:48:38 2014 user.info syslog: module is already loaded - cls_u32
Thu Oct  2 19:48:38 2014 kern.emerg already loaded - cls_u32
Thu Oct  2 19:48:38 2014 user.info syslog: module is already loaded - em_u32
Thu Oct  2 19:48:38 2014 kern.emerg already loaded - em_u32
Thu Oct  2 19:48:38 2014 user.info syslog: module is already loaded -
act_connmark
Thu Oct  2 19:48:38 2014 kern.emerg already loaded - act_connmark
Thu Oct  2 19:48:38 2014 user.info syslog: module is already loaded - act_mirred
Thu Oct  2 19:48:38 2014 kern.emerg already loaded - act_mirred
Thu Oct  2 19:48:38 2014 user.info syslog: module is already loaded -
sch_ingress
Thu Oct  2 19:48:38 2014 kern.emerg already loaded - sch_ingress
Thu Oct  2 19:48:38 2014 user.info syslog: module is already loaded - cls_fw
Thu Oct  2 19:48:38 2014 kern.emerg already loaded - cls_fw
Thu Oct  2 19:48:38 2014 user.info syslog: module is already loaded - sch_hfsc
Thu Oct  2 19:48:38 2014 kern.emerg already loaded - sch_hfsc
Thu Oct  2 19:48:38 2014 user.emerg syslog: Cannot find device "eth0.2"
Thu Oct  2 19:48:38 2014 user.emerg syslog: Cannot find device "eth0.2"
Thu Oct  2 19:48:38 2014 user.emerg syslog: Cannot find device "eth0.2"
Thu Oct  2 19:48:38 2014 user.emerg syslog: Cannot find device "eth0.2"
Thu Oct  2 19:48:38 2014 user.emerg syslog: Cannot find device "eth0.2"
Thu Oct  2 19:48:38 2014 user.emerg syslog: Cannot find device "eth0.2"
Thu Oct  2 19:48:38 2014 user.emerg syslog: Cannot find device "eth0.2"
Thu Oct  2 19:48:38 2014 user.emerg syslog: Cannot find device "eth0.2"
Thu Oct  2 19:48:38 2014 user.emerg syslog: Cannot find device "eth0.2"
Thu Oct  2 19:48:38 2014 user.emerg syslog: Cannot find device "eth0.2"
Thu Oct  2 19:48:39 2014 user.emerg syslog: Cannot find device "eth0.2"
Thu Oct  2 19:48:39 2014 user.emerg syslog: Cannot find device "eth0.2"
Thu Oct  2 19:48:39 2014 user.emerg syslog: Cannot find device "eth0.2"
Thu Oct  2 19:48:39 2014 user.emerg syslog: Cannot find device "eth0.2"
Thu Oct  2 19:48:39 2014 user.emerg syslog: Cannot find device "eth0.2"
Thu Oct  2 19:48:39 2014 user.emerg syslog: Cannot find device "eth0.2"
Thu Oct  2 19:48:39 2014 user.emerg syslog: Cannot find device "eth0.2"
Thu Oct  2 19:48:39 2014 user.emerg syslog: Cannot find device "eth0.2"
Thu Oct  2 19:48:39 2014 user.emerg syslog: Cannot find device "eth0.2"
Thu Oct  2 19:48:39 2014 user.emerg syslog: Cannot find device "eth0.2"
Thu Oct  2 19:48:39 2014 kern.info kernel: [   21.020000] IPv6:
ADDRCONF(NETDEV_UP): eth0: link is not ready
Thu Oct  2 19:48:39 2014 kern.info kernel: [   21.030000] IPv6:
ADDRCONF(NETDEV_UP): eth0.1: link is not ready
Thu Oct  2 19:48:39 2014 kern.info kernel: [   21.040000] device
eth0.1 entered promiscuous mode
Thu Oct  2 19:48:39 2014 kern.info kernel: [   21.040000] device eth0
entered promiscuous mode
Thu Oct  2 19:48:39 2014 daemon.notice netifd: Interface 'lan' is enabled
Thu Oct  2 19:48:39 2014 daemon.notice netifd: Interface 'lan' is setting up now
Thu Oct  2 19:48:39 2014 daemon.notice netifd: Interface 'lan' is now up
Thu Oct  2 19:48:39 2014 kern.info kernel: [   21.070000] IPv6:
ADDRCONF(NETDEV_UP): br-lan: link is not ready
Thu Oct  2 19:48:39 2014 daemon.notice netifd: Interface 'loopback' is enabled
Thu Oct  2 19:48:39 2014 daemon.notice netifd: Interface 'loopback' is
setting up now
Thu Oct  2 19:48:39 2014 daemon.notice netifd: Interface 'loopback' is now up
Thu Oct  2 19:48:39 2014 kern.info kernel: [   21.110000] IPv6:
ADDRCONF(NETDEV_UP): eth0.2: link is not ready
Thu Oct  2 19:48:39 2014 daemon.notice netifd: Interface 'wan' is enabled
Thu Oct  2 19:48:39 2014 daemon.notice netifd: Network device 'lo' link is up
Thu Oct  2 19:48:40 2014 daemon.notice netifd: Interface 'loopback'
has link connectivity
Thu Oct  2 19:48:40 2014 daemon.emerg logread[886]: Logread connected
to 192.168.8.103:514
Thu Oct  2 19:48:40 2014 kern.info kernel: [   21.630000] eth0: link
up (1000Mbps/Full duplex)
Thu Oct  2 19:48:40 2014 daemon.notice netifd: Network device 'eth0' link is up
Thu Oct  2 19:48:40 2014 daemon.notice netifd: VLAN 'eth0.2' link is up
Thu Oct  2 19:48:40 2014 daemon.notice netifd: Interface 'wan' has
link connectivity
Thu Oct  2 19:48:40 2014 daemon.notice netifd: Interface 'wan' is setting up now
Thu Oct  2 19:48:40 2014 daemon.notice netifd: VLAN 'eth0.1' link is up
Thu Oct  2 19:48:40 2014 kern.info kernel: [   21.660000] IPv6:
ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Thu Oct  2 19:48:40 2014 kern.info kernel: [   21.670000] br-lan: port
1(eth0.1) entered forwarding state
Thu Oct  2 19:48:40 2014 kern.info kernel: [   21.670000] br-lan: port
1(eth0.1) entered forwarding state
Thu Oct  2 19:48:40 2014 kern.info kernel: [   21.680000] IPv6:
ADDRCONF(NETDEV_CHANGE): eth0.1: link becomes ready
Thu Oct  2 19:48:40 2014 kern.info kernel: [   21.680000] IPv6:
ADDRCONF(NETDEV_CHANGE): eth0.2: link becomes ready
Thu Oct  2 19:48:40 2014 kern.info kernel: [   21.690000] IPv6:
ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready
Thu Oct  2 19:48:40 2014 daemon.notice netifd: Bridge 'br-lan' link is up
Thu Oct  2 19:48:40 2014 daemon.notice netifd: Interface 'lan' has
link connectivity
Thu Oct  2 19:48:42 2014 daemon.info pppd[1472]: Plugin rp-pppoe.so loaded.
Thu Oct  2 19:48:42 2014 daemon.info pppd[1472]: RP-PPPoE plugin
version 3.8p compiled against pppd 2.4.7
Thu Oct  2 19:48:42 2014 daemon.notice pppd[1472]: pppd 2.4.7 started
by root, uid 0
Thu Oct  2 19:48:42 2014 daemon.debug pppd[1472]: Send PPPOE Discovery
V1T1 PADI session 0x0 length 12
Thu Oct  2 19:48:42 2014 daemon.debug pppd[1472]:  dst
ff:ff:ff:ff:ff:ff  src 64:70:02:e2:a4:28
Thu Oct  2 19:48:42 2014 daemon.debug pppd[1472]:  [service-name]
[host-uniq  00 00 05 c0]
Thu Oct  2 19:48:42 2014 daemon.debug pppd[1472]: Recv PPPOE Discovery
V1T1 PADO session 0x0 length 47
Thu Oct  2 19:48:42 2014 daemon.debug pppd[1472]:  dst
64:70:02:e2:a4:28  src 8c:90:d3:32:21:75
Thu Oct  2 19:48:42 2014 daemon.debug pppd[1472]:  [service-name]
[AC-name WDBGON4838W] [host-uniq  00 00 05 c0] [AC-cookie  d1 3f 3a 2c
85 d9 98 51 71 3d eb e0 a8 1c 8a 6f]
Thu Oct  2 19:48:42 2014 daemon.debug pppd[1472]: Send PPPOE Discovery
V1T1 PADR session 0x0 length 32
Thu Oct  2 19:48:42 2014 daemon.debug pppd[1472]:  dst
8c:90:d3:32:21:75  src 64:70:02:e2:a4:28
Thu Oct  2 19:48:42 2014 daemon.debug pppd[1472]:  [service-name]
[host-uniq  00 00 05 c0] [AC-cookie  d1 3f 3a 2c 85 d9 98 51 71 3d eb
e0 a8 1c 8a 6f]
Thu Oct  2 19:48:42 2014 daemon.debug pppd[1472]: Recv PPPOE Discovery
V1T1 PADS session 0x1 length 12
Thu Oct  2 19:48:42 2014 daemon.debug pppd[1472]:  dst
64:70:02:e2:a4:28  src 8c:90:d3:32:21:75
Thu Oct  2 19:48:42 2014 daemon.debug pppd[1472]:  [service-name]
[host-uniq  00 00 05 c0]
Thu Oct  2 19:48:42 2014 daemon.debug pppd[1472]: PADS: Service-Name: ''
Thu Oct  2 19:48:42 2014 daemon.info pppd[1472]: PPP session is 1
Thu Oct  2 19:48:42 2014 daemon.warn pppd[1472]: Connected to
8c:90:d3:32:21:75 via interface eth0.2
Thu Oct  2 19:48:42 2014 kern.info kernel: [   23.670000] br-lan: port
1(eth0.1) entered forwarding state
Thu Oct  2 19:48:42 2014 daemon.debug pppd[1472]: using channel 1
Thu Oct  2 19:48:42 2014 daemon.info pppd[1472]: Using interface pppoe-wan
Thu Oct  2 19:48:42 2014 daemon.notice pppd[1472]: Connect: pppoe-wan
<--> eth0.2
Thu Oct  2 19:48:42 2014 daemon.debug pppd[1472]: sent [LCP ConfReq
id=0x1 <mru 1492> <magic 0x425f1d1b>]
Thu Oct  2 19:48:42 2014 daemon.debug pppd[1472]: rcvd [LCP ConfAck
id=0x1 <mru 1492> <magic 0x425f1d1b>]
Thu Oct  2 19:48:42 2014 kern.info kernel: [   23.970000] IPv6:
ADDRCONF(NETDEV_UP): wlan1: link is not ready
Thu Oct  2 19:48:42 2014 kern.info kernel: [   23.970000] device wlan1
entered promiscuous mode
Thu Oct  2 19:48:42 2014 kern.info kernel: [   24.000000] IPv6:
ADDRCONF(NETDEV_UP): wlan0: link is not ready
Thu Oct  2 19:48:42 2014 kern.info kernel: [   24.050000] device wlan0
entered promiscuous mode
Thu Oct  2 19:48:42 2014 kern.info kernel: [   24.050000] br-lan: port
3(wlan0) entered forwarding state
Thu Oct  2 19:48:42 2014 kern.info kernel: [   24.060000] br-lan: port
3(wlan0) entered forwarding state
Thu Oct  2 19:48:43 2014 user.notice firewall: Reloading firewall due
to ifup of lan (br-lan)
Thu Oct  2 19:48:43 2014 kern.info kernel: [   25.040000] br-lan: port
3(wlan0) entered disabled state
Thu Oct  2 19:48:44 2014 kern.info kernel: [   26.140000] br-lan: port
3(wlan0) entered forwarding state
Thu Oct  2 19:48:44 2014 kern.info kernel: [   26.140000] br-lan: port
3(wlan0) entered forwarding state
Thu Oct  2 19:48:44 2014 kern.info kernel: [   26.150000] IPv6:
ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Thu Oct  2 19:48:44 2014 kern.info kernel: [   26.150000] br-lan: port
2(wlan1) entered forwarding state
Thu Oct  2 19:48:44 2014 kern.info kernel: [   26.160000] br-lan: port
2(wlan1) entered forwarding state
Thu Oct  2 19:48:44 2014 kern.info kernel: [   26.160000] IPv6:
ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
Thu Oct  2 19:48:45 2014 daemon.notice netifd: Network device 'wlan0' link is up
Thu Oct  2 19:48:45 2014 daemon.notice netifd: Network device 'wlan1' link is up
Thu Oct  2 19:48:45 2014 user.info syslog: module is already loaded - cls_u32
Thu Oct  2 19:48:45 2014 kern.emerg already loaded - cls_u32
Thu Oct  2 19:48:45 2014 user.info syslog: module is already loaded - em_u32
Thu Oct  2 19:48:45 2014 kern.emerg already loaded - em_u32
Thu Oct  2 19:48:45 2014 user.info syslog: module is already loaded -
act_connmark
Thu Oct  2 19:48:45 2014 kern.emerg already loaded - act_connmark
Thu Oct  2 19:48:45 2014 daemon.debug pppd[1472]: sent [LCP ConfReq
id=0x1 <mru 1492> <magic 0x425f1d1b>]
Thu Oct  2 19:48:45 2014 user.info syslog: module is already loaded - act_mirred
Thu Oct  2 19:48:45 2014 kern.emerg already loaded - act_mirred
Thu Oct  2 19:48:45 2014 daemon.debug pppd[1472]: rcvd [LCP ConfAck
id=0x1 <mru 1492> <magic 0x425f1d1b>]
Thu Oct  2 19:48:45 2014 daemon.debug pppd[1472]: rcvd [LCP ConfReq
id=0xd8 <mru 1492> <auth pap> <magic 0x37b3c176>]
Thu Oct  2 19:48:45 2014 daemon.debug pppd[1472]: sent [LCP ConfAck
id=0xd8 <mru 1492> <auth pap> <magic 0x37b3c176>]
Thu Oct  2 19:48:45 2014 daemon.debug pppd[1472]: sent [LCP EchoReq
id=0x0 magic=0x425f1d1b]
Thu Oct  2 19:48:45 2014 user.info syslog: module is already loaded -
sch_ingress
Thu Oct  2 19:48:45 2014 kern.emerg already loaded - sch_ingress
Thu Oct  2 19:48:45 2014 daemon.debug pppd[1472]: rcvd [LCP EchoRep
id=0x0 magic=0x37b3c176]
Thu Oct  2 19:48:45 2014 user.info syslog: module is already loaded - cls_fw
Thu Oct  2 19:48:45 2014 kern.emerg already loaded - cls_fw
Thu Oct  2 19:48:45 2014 user.info syslog: module is already loaded - sch_hfsc
Thu Oct  2 19:48:45 2014 kern.emerg already loaded - sch_hfsc
Thu Oct  2 19:48:45 2014 daemon.debug pppd[1472]: rcvd [PAP AuthAck id=0x1 ""]
Thu Oct  2 19:48:45 2014 daemon.notice pppd[1472]: PAP authentication succeeded
Thu Oct  2 19:48:45 2014 daemon.notice pppd[1472]: peer from calling
number 8C:90:D3:32:21:75 authorized
Thu Oct  2 19:48:45 2014 daemon.debug pppd[1472]: sent [IPCP ConfReq
id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Thu Oct  2 19:48:46 2014 daemon.debug pppd[1472]: rcvd [IPCP ConfReq
id=0x24 <addr 206.248.154.122>]
Thu Oct  2 19:48:46 2014 daemon.debug pppd[1472]: sent [IPCP ConfAck
id=0x24 <addr 206.248.154.122>]
Thu Oct  2 19:48:46 2014 daemon.debug pppd[1472]: rcvd [IPCP ConfNak
id=0x1 <addr 108.161.123.195> <ms-dns1 206.248.154.22> <ms-dns2
206.248.154.170>]
Thu Oct  2 19:48:46 2014 daemon.debug pppd[1472]: sent [IPCP ConfReq
id=0x2 <addr 108.161.123.195> <ms-dns1 206.248.154.22> <ms-dns2
206.248.154.170>]
Thu Oct  2 19:48:46 2014 daemon.debug pppd[1472]: rcvd [IPCP ConfAck
id=0x2 <addr 108.161.123.195> <ms-dns1 206.248.154.22> <ms-dns2
206.248.154.170>]
Thu Oct  2 19:48:46 2014 daemon.notice pppd[1472]: local  IP address
108.161.123.195
Thu Oct  2 19:48:46 2014 daemon.notice pppd[1472]: remote IP address
206.248.154.122
Thu Oct  2 19:48:46 2014 daemon.notice pppd[1472]: primary   DNS
address 206.248.154.22
Thu Oct  2 19:48:46 2014 daemon.notice pppd[1472]: secondary DNS
address 206.248.154.170
Thu Oct  2 19:48:46 2014 daemon.debug pppd[1472]: Script
/lib/netifd/ppp-up started (pid 1773)
Thu Oct  2 19:48:46 2014 daemon.notice netifd: Network device
'pppoe-wan' link is up
Thu Oct  2 19:48:46 2014 daemon.notice netifd: Interface 'wan' is now up
Thu Oct  2 19:48:46 2014 daemon.debug pppd[1472]: Script
/lib/netifd/ppp-up finished (pid 1773), status = 0x1
Thu Oct  2 19:48:46 2014 kern.info kernel: [   28.140000] br-lan: port
3(wlan0) entered forwarding state
Thu Oct  2 19:48:46 2014 kern.info kernel: [   28.160000] br-lan: port
2(wlan1) entered forwarding state
Thu Oct  2 19:48:47 2014 daemon.debug xinetd[1881]: Reading included
configuration file: /etc/xinetd.d/munin [file=/etc/xinetd.conf]
[line=6]
Thu Oct  2 19:48:47 2014 daemon.notice xinetd[1881]: xinetd Version
2.3.15 started with loadavg options compiled in.
Thu Oct  2 19:48:47 2014 daemon.notice xinetd[1881]: Started working:
1 available service
Thu Oct  2 19:48:48 2014 user.emerg syslog: darkstat (01889): local
network address: 192.168.8.0
Thu Oct  2 19:48:48 2014 user.emerg syslog: darkstat (01889):    local
network mask: 255.255.255.0
Thu Oct  2 19:48:48 2014 user.emerg syslog: darkstat (01889): max 1000
hosts, cutting down to 500 when exceeded
Thu Oct  2 19:48:48 2014 user.emerg syslog: darkstat (01889): max 200
ports per host, cutting down to 30 when exceeded
Thu Oct  2 19:48:48 2014 user.emerg syslog: darkstat (01889): starting up
Thu Oct  2 19:48:48 2014 user.emerg syslog: darkstat (01889):
daemonizing to run in the background!
Thu Oct  2 19:48:48 2014 user.emerg syslog: darkstat (01889): parent waiting
Thu Oct  2 19:48:48 2014 user.emerg syslog: darkstat (01890): I am the
main process
Thu Oct  2 19:48:48 2014 user.emerg syslog: darkstat (01890): DNS
child has PID 1891
Thu Oct  2 19:48:48 2014 user.emerg syslog: darkstat (01891): set
uid/gid to 65534/65534
Thu Oct  2 19:48:48 2014 user.emerg syslog: darkstat (01890): linktype is 1
Thu Oct  2 19:48:48 2014 user.emerg syslog: darkstat (01890):
calculated snaplen minimum 74
Thu Oct  2 19:48:48 2014 user.emerg syslog: darkstat (01890): using snaplen 96
Thu Oct  2 19:48:48 2014 kern.info kernel: [   29.330000] device
br-lan entered promiscuous mode
Thu Oct  2 19:48:48 2014 user.emerg syslog: darkstat (01890):
capturing in promiscuous mode
Thu Oct  2 19:48:48 2014 user.emerg syslog: darkstat (01890):
listening on http://192.168.8.1:667/
Thu Oct  2 19:48:48 2014 user.emerg syslog: darkstat (01890): loaded 45 protos
Thu Oct  2 19:48:48 2014 user.emerg syslog: darkstat (01890): loaded
99 tcp and 71 udp servs, from total 170
Thu Oct  2 19:48:48 2014 user.emerg syslog: darkstat (01890): chrooted
into: /var/empty
Thu Oct  2 19:48:48 2014 user.emerg syslog: darkstat (01890): set
uid/gid to 65534/65534
Thu Oct  2 19:48:48 2014 user.emerg syslog: darkstat (01890): br-lan
ip4 update: 192.168.8.1
Thu Oct  2 19:48:48 2014 user.emerg syslog: darkstat (01890): entering main loop
Thu Oct  2 19:48:48 2014 user.emerg syslog: darkstat (01889): parent
done reading, calling waitpid
Thu Oct  2 19:48:48 2014 user.emerg syslog: darkstat (01889): waitpid
ret 0, status is 2037672291
Thu Oct  2 19:48:48 2014 user.emerg syslog: jffs2 is not ready - marker found
Thu Oct  2 19:48:48 2014 user.emerg syslog: jffs2 is not ready - marker found
Thu Oct  2 19:48:48 2014 kern.warn kernel: [   29.460000]
jffs2_scan_eraseblock(): End of filesystem marker found at 0x0
Thu Oct  2 19:48:48 2014 kern.warn kernel: [   29.470000]
jffs2_build_filesystem(): unlocking the mtd device... done.
Thu Oct  2 19:48:49 2014 daemon.info dnsmasq[1906]: started, version
2.72 cachesize 4096
Thu Oct  2 19:48:49 2014 daemon.info dnsmasq[1906]: 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 loop-detect
Thu Oct  2 19:48:49 2014 daemon.info dnsmasq-dhcp[1906]: DHCP, IP
range 192.168.8.150 -- 192.168.8.199, lease time 3h
Thu Oct  2 19:48:49 2014 daemon.info dnsmasq[1906]: using local
addresses only for domain lan
Thu Oct  2 19:48:49 2014 daemon.info dnsmasq[1906]: reading
/etc/resolv.conf.opendns
Thu Oct  2 19:48:49 2014 daemon.info dnsmasq[1906]: using local
addresses only for domain lan
Thu Oct  2 19:48:49 2014 daemon.info dnsmasq[1906]: using nameserver
66.163.0.161#53
Thu Oct  2 19:48:49 2014 daemon.info dnsmasq[1906]: using nameserver
206.248.154.170#53
Thu Oct  2 19:48:49 2014 daemon.info dnsmasq[1906]: using nameserver
206.248.154.22#53
Thu Oct  2 19:48:49 2014 daemon.info dnsmasq[1906]: using nameserver
142.46.128.130#53
Thu Oct  2 19:48:49 2014 daemon.info dnsmasq[1906]: using nameserver 8.8.4.4#53
Thu Oct  2 19:48:49 2014 daemon.info dnsmasq[1906]: read /etc/hosts -
5 addresses
Thu Oct  2 19:48:49 2014 daemon.info dnsmasq[1906]: read
/tmp/hosts/dhcp - 1 addresses
Thu Oct  2 19:48:49 2014 daemon.info dnsmasq-dhcp[1906]: read
/etc/ethers - 13 addresses
Thu Oct  2 19:48:50 2014 daemon.notice miniupnpd[1941]: HTTP listening
on port 5000
Thu Oct  2 19:48:50 2014 daemon.warn miniupnpd[1941]: no HTTP IPv6
address, disabling IPv6
Thu Oct  2 19:48:53 2014 daemon.info dnsmasq[1906]: exiting on receipt
of SIGTERM
Thu Oct  2 19:48:53 2014 daemon.info dnsmasq[2020]: started, version
2.72 cachesize 4096
Thu Oct  2 19:48:53 2014 daemon.info dnsmasq[2020]: 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 loop-detect
Thu Oct  2 19:48:53 2014 daemon.info dnsmasq-dhcp[2020]: DHCP, IP
range 192.168.8.150 -- 192.168.8.199, lease time 3h
Thu Oct  2 19:48:53 2014 daemon.info dnsmasq[2020]: using local
addresses only for domain lan
Thu Oct  2 19:48:53 2014 daemon.info dnsmasq[2020]: reading
/etc/resolv.conf.opendns
Thu Oct  2 19:48:53 2014 daemon.info dnsmasq[2020]: using local
addresses only for domain lan
Thu Oct  2 19:48:53 2014 daemon.info dnsmasq[2020]: using nameserver
66.163.0.161#53
Thu Oct  2 19:48:53 2014 daemon.info dnsmasq[2020]: using nameserver
206.248.154.170#53
Thu Oct  2 19:48:53 2014 daemon.info dnsmasq[2020]: using nameserver
206.248.154.22#53
Thu Oct  2 19:48:53 2014 daemon.info dnsmasq[2020]: using nameserver
142.46.128.130#53
Thu Oct  2 19:48:53 2014 daemon.info dnsmasq[2020]: using nameserver 8.8.4.4#53
Thu Oct  2 19:48:53 2014 daemon.info dnsmasq[2020]: read /etc/hosts -
5 addresses
Thu Oct  2 19:48:53 2014 daemon.info dnsmasq[2020]: read
/tmp/hosts/dhcp - 1 addresses
Thu Oct  2 19:48:53 2014 daemon.info dnsmasq-dhcp[2020]: read
/etc/ethers - 13 addresses
Thu Oct  2 19:48:54 2014 kern.info kernel: [   35.790000]
nf_conntrack: automatic helper assignment is deprecated and it will be
removed soon. Use the iptables CT target to attach helpers instead.
Thu Oct  2 19:48:55 2014 user.info syslog: module is already loaded - cls_u32
Thu Oct  2 19:48:55 2014 kern.emerg already loaded - cls_u32
Thu Oct  2 19:48:55 2014 user.info syslog: module is already loaded - em_u32
Thu Oct  2 19:48:55 2014 kern.emerg already loaded - em_u32
Thu Oct  2 19:48:55 2014 user.info syslog: module is already loaded -
act_connmark
Thu Oct  2 19:48:55 2014 kern.emerg already loaded - act_connmark
Thu Oct  2 19:48:55 2014 user.info syslog: module is already loaded - act_mirred
Thu Oct  2 19:48:55 2014 kern.emerg already loaded - act_mirred
Thu Oct  2 19:48:55 2014 user.info syslog: module is already loaded -
sch_ingress
Thu Oct  2 19:48:55 2014 kern.emerg already loaded - sch_ingress
Thu Oct  2 19:48:55 2014 user.info syslog: module is already loaded - cls_fw
Thu Oct  2 19:48:55 2014 kern.emerg already loaded - cls_fw
Thu Oct  2 19:48:55 2014 user.info syslog: module is already loaded - sch_hfsc
Thu Oct  2 19:48:55 2014 kern.emerg already loaded - sch_hfsc
Thu Oct  2 19:48:56 2014 user.notice firewall: Reloading firewall due
to ifup of wan (pppoe-wan)
Thu Oct  2 19:48:58 2014 daemon.notice miniupnpd[1941]: shutting down MiniUPnPd
Thu Oct  2 19:48:58 2014 daemon.err miniupnpd[1941]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:48:58 2014 daemon.err miniupnpd[1941]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:48:58 2014 daemon.err miniupnpd[1941]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:48:58 2014 daemon.err miniupnpd[1941]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:48:58 2014 daemon.err miniupnpd[1941]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:48:58 2014 daemon.err miniupnpd[1941]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:48:58 2014 daemon.err miniupnpd[1941]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:48:58 2014 daemon.err miniupnpd[1941]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:48:58 2014 daemon.err miniupnpd[1941]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:48:58 2014 daemon.err miniupnpd[1941]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:48:58 2014 daemon.err miniupnpd[1941]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:48:58 2014 daemon.err miniupnpd[1941]: Failed to
broadcast good-bye notifications
Thu Oct  2 19:48:59 2014 daemon.notice miniupnpd[2249]: HTTP listening
on port 5000
Thu Oct  2 19:48:59 2014 daemon.warn miniupnpd[2249]: no HTTP IPv6
address, disabling IPv6
Thu Oct  2 19:49:01 2014 cron.info crond[966]: crond: USER root pid
2253 cmd /bin/sh /etc/netCheck.sh
Thu Oct  2 19:49:05 2014 kern.warn kernel: [   29.480000]
jffs2_build_filesystem(): erasing all blocks after the end marker...
done.
Thu Oct  2 19:49:05 2014 kern.notice kernel: [   46.350000] jffs2:
notice: (1893) jffs2_build_xattr_subsystem: complete building xattr
subsystem, 0 of xdatum (0 unchecked, 0 orphan) and 0 of xref (0 dead,
0 orphan) found.
Thu Oct  2 19:49:05 2014 user.emerg syslog: doing fo cleanup
Thu Oct  2 19:49:05 2014 kern.info kernel: [   46.740000] eth0: link down
Thu Oct  2 19:49:05 2014 kern.info kernel: [   46.740000] br-lan: port
1(eth0.1) entered disabled state
Thu Oct  2 19:49:05 2014 daemon.notice netifd: Network device 'eth0'
link is down
Thu Oct  2 19:49:05 2014 daemon.notice netifd: VLAN 'eth0.2' link is down
Thu Oct  2 19:49:05 2014 daemon.notice netifd: Interface 'wan' has
link connectivity loss
Thu Oct  2 19:49:05 2014 daemon.notice netifd: VLAN 'eth0.1' link is down
Thu Oct  2 19:49:05 2014 kern.info kernel: [   46.890000] eth0: link
up (1000Mbps/Full duplex)
Thu Oct  2 19:49:05 2014 daemon.notice netifd: Network device 'eth0' link is up
Thu Oct  2 19:49:05 2014 daemon.notice netifd: VLAN 'eth0.2' link is up
Thu Oct  2 19:49:05 2014 daemon.notice netifd: Interface 'wan' has
link connectivity
Thu Oct  2 19:49:05 2014 daemon.notice netifd: Interface 'wan' is setting up now
Thu Oct  2 19:49:05 2014 daemon.notice netifd: VLAN 'eth0.1' link is up
Thu Oct  2 19:49:05 2014 kern.info kernel: [   46.920000] br-lan: port
1(eth0.1) entered forwarding state
Thu Oct  2 19:49:05 2014 kern.info kernel: [   46.930000] br-lan: port
1(eth0.1) entered forwarding state
Thu Oct  2 19:49:06 2014 daemon.notice netifd: Network device
'pppoe-wan' link is down
Thu Oct  2 19:49:06 2014 daemon.info pppd[2403]: Plugin rp-pppoe.so loaded.
Thu Oct  2 19:49:06 2014 daemon.info pppd[2403]: RP-PPPoE plugin
version 3.8p compiled against pppd 2.4.7
Thu Oct  2 19:49:06 2014 daemon.notice pppd[2403]: pppd 2.4.7 started
by root, uid 0
Thu Oct  2 19:49:06 2014 daemon.debug pppd[2403]: Send PPPOE Discovery
V1T1 PADI session 0x0 length 12
Thu Oct  2 19:49:06 2014 daemon.debug pppd[2403]:  dst
ff:ff:ff:ff:ff:ff  src 64:70:02:e2:a4:28
Thu Oct  2 19:49:06 2014 daemon.debug pppd[2403]:  [service-name]
[host-uniq  00 00 09 63]
Thu Oct  2 19:49:06 2014 daemon.debug pppd[2403]: Recv PPPOE Discovery
V1T1 PADO session 0x0 length 47
Thu Oct  2 19:49:06 2014 daemon.debug pppd[2403]:  dst
64:70:02:e2:a4:28  src 8c:90:d3:32:21:75
Thu Oct  2 19:49:06 2014 daemon.debug pppd[2403]:  [service-name]
[AC-name WDBGON4838W] [host-uniq  00 00 09 63] [AC-cookie  d1 3f 3a 2c
85 d9 98 51 71 3d eb e0 a8 1c 8a 6f]
Thu Oct  2 19:49:06 2014 daemon.debug pppd[2403]: Send PPPOE Discovery
V1T1 PADR session 0x0 length 32
Thu Oct  2 19:49:06 2014 daemon.debug pppd[2403]:  dst
8c:90:d3:32:21:75  src 64:70:02:e2:a4:28
Thu Oct  2 19:49:06 2014 daemon.debug pppd[2403]:  [service-name]
[host-uniq  00 00 09 63] [AC-cookie  d1 3f 3a 2c 85 d9 98 51 71 3d eb
e0 a8 1c 8a 6f]
Thu Oct  2 19:49:06 2014 daemon.debug pppd[2403]: Recv PPPOE Discovery
V1T1 PADS session 0x2 length 12
Thu Oct  2 19:49:06 2014 daemon.debug pppd[2403]:  dst
64:70:02:e2:a4:28  src 8c:90:d3:32:21:75
Thu Oct  2 19:49:06 2014 daemon.debug pppd[2403]:  [service-name]
[host-uniq  00 00 09 63]
Thu Oct  2 19:49:06 2014 daemon.debug pppd[2403]: PADS: Service-Name: ''
Thu Oct  2 19:49:06 2014 daemon.info pppd[2403]: PPP session is 2
Thu Oct  2 19:49:06 2014 daemon.warn pppd[2403]: Connected to
8c:90:d3:32:21:75 via interface eth0.2
Thu Oct  2 19:49:06 2014 daemon.debug pppd[2403]: using channel 2
Thu Oct  2 19:49:06 2014 daemon.info pppd[2403]: Using interface pppoe-wan
Thu Oct  2 19:49:06 2014 daemon.notice pppd[2403]: Connect: pppoe-wan
<--> eth0.2
Thu Oct  2 19:49:06 2014 daemon.debug pppd[2403]: sent [LCP ConfReq
id=0x1 <mru 1492> <magic 0x33ccf270>]
Thu Oct  2 19:49:06 2014 daemon.debug pppd[2403]: rcvd [LCP ConfAck
id=0x1 <mru 1492> <magic 0x33ccf270>]
Thu Oct  2 19:49:06 2014 user.emerg syslog: setting up led USB1
Thu Oct  2 19:49:06 2014 user.emerg syslog: setting up led USB2
Thu Oct  2 19:49:06 2014 user.emerg syslog: setting up led WLAN2G
Thu Oct  2 19:49:06 2014 user.emerg syslog: - init complete -
Thu Oct  2 19:49:07 2014 kern.info kernel: [   48.930000] br-lan: port
1(eth0.1) entered forwarding state
Thu Oct  2 19:49:08 2014 authpriv.info dropbear[2478]: Child
connection from 192.168.8.10:34701
Thu Oct  2 19:49:08 2014 authpriv.notice dropbear[2478]: Pubkey auth
succeeded for 'root' with key md5
fd:66:14:b2:ba:a2:61:67:05:4e:09:1b:8b:79:18:aa from
192.168.8.10:34701
Thu Oct  2 19:49:09 2014 daemon.debug pppd[2403]: rcvd [LCP ConfReq
id=0x15 <mru 1492> <auth pap> <magic 0x136d7a94>]
Thu Oct  2 19:49:09 2014 daemon.debug pppd[2403]: sent [LCP ConfAck
id=0x15 <mru 1492> <auth pap> <magic 0x136d7a94>]
Thu Oct  2 19:49:09 2014 daemon.debug pppd[2403]: sent [LCP EchoReq
id=0x0 magic=0x33ccf270]
Thu Oct  2 19:49:09 2014 daemon.debug pppd[2403]: rcvd [LCP EchoRep
id=0x0 magic=0x136d7a94]
Thu Oct  2 19:49:09 2014 daemon.debug pppd[2403]: rcvd [PAP AuthAck id=0x1 ""]
Thu Oct  2 19:49:09 2014 daemon.notice pppd[2403]: PAP authentication succeeded
Thu Oct  2 19:49:09 2014 daemon.notice pppd[2403]: peer from calling
number 8C:90:D3:32:21:75 authorized
Thu Oct  2 19:49:09 2014 daemon.debug pppd[2403]: sent [IPCP ConfReq
id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Thu Oct  2 19:49:09 2014 daemon.debug pppd[2403]: rcvd [IPCP ConfReq
id=0x3 <addr 206.248.154.122>]
Thu Oct  2 19:49:09 2014 daemon.debug pppd[2403]: sent [IPCP ConfAck
id=0x3 <addr 206.248.154.122>]
Thu Oct  2 19:49:09 2014 daemon.debug pppd[2403]: rcvd [IPCP ConfNak
id=0x1 <addr 108.161.115.28> <ms-dns1 206.248.154.22> <ms-dns2
206.248.154.170>]
Thu Oct  2 19:49:09 2014 daemon.debug pppd[2403]: sent [IPCP ConfReq
id=0x2 <addr 108.161.115.28> <ms-dns1 206.248.154.22> <ms-dns2
206.248.154.170>]
Thu Oct  2 19:49:09 2014 daemon.debug pppd[2403]: rcvd [IPCP ConfAck
id=0x2 <addr 108.161.115.28> <ms-dns1 206.248.154.22> <ms-dns2
206.248.154.170>]
Thu Oct  2 19:49:09 2014 daemon.notice pppd[2403]: local  IP address
108.161.115.28
Thu Oct  2 19:49:09 2014 daemon.notice pppd[2403]: remote IP address
206.248.154.122
Thu Oct  2 19:49:09 2014 daemon.notice pppd[2403]: primary   DNS
address 206.248.154.22
Thu Oct  2 19:49:09 2014 daemon.notice pppd[2403]: secondary DNS
address 206.248.154.170
Thu Oct  2 19:49:09 2014 daemon.notice netifd: Network device
'pppoe-wan' link is up
Thu Oct  2 19:49:09 2014 daemon.debug pppd[2403]: Script
/lib/netifd/ppp-up started (pid 2484)
Thu Oct  2 19:49:09 2014 daemon.notice netifd: Interface 'wan' is now up
Thu Oct  2 19:49:09 2014 daemon.debug pppd[2403]: Script
/lib/netifd/ppp-up finished (pid 2484), status = 0x1
Thu Oct  2 19:49:10 2014 user.info syslog: module is already loaded - cls_u32
Thu Oct  2 19:49:10 2014 kern.emerg already loaded - cls_u32
Thu Oct  2 19:49:10 2014 user.info syslog: module is already loaded - em_u32
Thu Oct  2 19:49:10 2014 kern.emerg already loaded - em_u32
Thu Oct  2 19:49:10 2014 user.info syslog: module is already loaded -
act_connmark
Thu Oct  2 19:49:10 2014 kern.emerg already loaded - act_connmark
Thu Oct  2 19:49:10 2014 user.info syslog: module is already loaded - act_mirred
Thu Oct  2 19:49:10 2014 kern.emerg already loaded - act_mirred
Thu Oct  2 19:49:10 2014 user.info syslog: module is already loaded -
sch_ingress
Thu Oct  2 19:49:10 2014 kern.emerg already loaded - sch_ingress
Thu Oct  2 19:49:10 2014 user.info syslog: module is already loaded - cls_fw
Thu Oct  2 19:49:10 2014 kern.emerg already loaded - cls_fw
Thu Oct  2 19:49:10 2014 user.info syslog: module is already loaded - sch_hfsc
Thu Oct  2 19:49:10 2014 kern.emerg already loaded - sch_hfsc
Thu Oct  2 19:49:10 2014 daemon.notice netifd: Network device
'pppoe-wan' link is down
Thu Oct  2 19:49:10 2014 user.notice firewall: Reloading firewall due
to ifup of wan (pppoe-wan)
Thu Oct  2 19:49:11 2014 daemon.notice miniupnpd[2249]: shutting down MiniUPnPd
Thu Oct  2 19:49:11 2014 daemon.err miniupnpd[2249]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:49:11 2014 daemon.err miniupnpd[2249]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:49:11 2014 daemon.err miniupnpd[2249]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:49:11 2014 daemon.err miniupnpd[2249]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:49:11 2014 daemon.err miniupnpd[2249]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:49:11 2014 daemon.err miniupnpd[2249]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:49:11 2014 daemon.err miniupnpd[2249]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:49:11 2014 daemon.err miniupnpd[2249]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:49:11 2014 daemon.err miniupnpd[2249]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:49:11 2014 daemon.err miniupnpd[2249]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:49:12 2014 daemon.notice miniupnpd[2757]: HTTP listening
on port 5000
Thu Oct  2 19:49:12 2014 daemon.warn miniupnpd[2757]: no HTTP IPv6
address, disabling IPv6
Thu Oct  2 19:49:19 2014 user.notice netCheck: Number of external
hosts unavalible: 4
Thu Oct  2 19:49:19 2014 user.notice netCheck: Skipping, just rebooted.
Thu Oct  2 19:49:19 2014 user.notice hotplug.d: Calling netCheck.sh to
make sure everything is sane...
Thu Oct  2 19:53:25 2014 user.notice hotplug.d: Calling netCheck.sh to
make sure everything is sane...
Thu Oct  2 19:53:27 2014 user.notice netCheck: Number of external
hosts unavalible: 4
Thu Oct  2 19:53:27 2014 user.notice netCheck: Skipping, just rebooted.
Thu Oct  2 19:53:39 2014 user.notice netCheck: Number of external
hosts unavalible: 4
Thu Oct  2 19:53:39 2014 user.notice netCheck: Skipping, just rebooted.
Thu Oct  2 19:53:51 2014 user.notice netCheck: Number of external
hosts unavalible: 4
Thu Oct  2 19:53:51 2014 user.notice netCheck: Skipping, just rebooted.
Thu Oct  2 19:54:03 2014 user.notice netCheck: Number of external
hosts unavalible: 4
Thu Oct  2 19:54:03 2014 user.notice netCheck: Skipping, just rebooted.
Thu Oct  2 19:54:16 2014 user.notice netCheck: Number of external
hosts unavalible: 4
Thu Oct  2 19:54:16 2014 user.notice netCheck: Skipping, just rebooted.
Thu Oct  2 19:54:28 2014 user.notice netCheck: Number of external
hosts unavalible: 4
Thu Oct  2 19:54:28 2014 user.notice netCheck: Skipping, just rebooted.
Thu Oct  2 19:54:40 2014 user.notice netCheck: Number of external
hosts unavalible: 4
Thu Oct  2 19:54:40 2014 user.notice netCheck: Skipping, just rebooted.
Thu Oct  2 19:54:52 2014 user.notice netCheck: Number of external
hosts unavalible: 4
Thu Oct  2 19:54:52 2014 user.notice netCheck: Skipping, just rebooted.
Thu Oct  2 19:55:04 2014 user.notice netCheck: Number of external
hosts unavalible: 4
Thu Oct  2 19:55:04 2014 user.notice netCheck: Skipping, just rebooted.
Thu Oct  2 19:55:17 2014 user.notice netCheck: Number of external
hosts unavalible: 4
Thu Oct  2 19:55:17 2014 user.notice netCheck: Restarting WAN
Thu Oct  2 19:55:17 2014 daemon.notice netifd: Interface 'wan' is now down
Thu Oct  2 19:55:17 2014 kern.info kernel: [  185.540000] IPv6:
ADDRCONF(NETDEV_UP): eth0.2: link is not ready
Thu Oct  2 19:55:17 2014 daemon.notice netifd: Interface 'wan' is disabled
Thu Oct  2 19:55:17 2014 daemon.notice netifd: VLAN 'eth0.2' link is down
Thu Oct  2 19:55:17 2014 daemon.notice netifd: Interface 'wan' has
link connectivity loss
Thu Oct  2 19:55:19 2014 daemon.notice netifd: Interface 'wan' is enabled
Thu Oct  2 19:55:19 2014 daemon.notice netifd: VLAN 'eth0.2' link is up
Thu Oct  2 19:55:19 2014 daemon.notice netifd: Interface 'wan' has
link connectivity
Thu Oct  2 19:55:19 2014 daemon.notice netifd: Interface 'wan' is setting up now
Thu Oct  2 19:55:19 2014 daemon.info pppd[4355]: Plugin rp-pppoe.so loaded.
Thu Oct  2 19:55:19 2014 daemon.info pppd[4355]: RP-PPPoE plugin
version 3.8p compiled against pppd 2.4.7
Thu Oct  2 19:55:19 2014 daemon.notice pppd[4355]: pppd 2.4.7 started
by root, uid 0
Thu Oct  2 19:55:19 2014 daemon.debug pppd[4355]: Send PPPOE Discovery
V1T1 PADI session 0x0 length 12
Thu Oct  2 19:55:19 2014 daemon.debug pppd[4355]:  dst
ff:ff:ff:ff:ff:ff  src 64:70:02:e2:a4:28
Thu Oct  2 19:55:19 2014 daemon.debug pppd[4355]:  [service-name]
[host-uniq  00 00 11 03]
Thu Oct  2 19:55:19 2014 daemon.debug pppd[4355]: Recv PPPOE Discovery
V1T1 PADO session 0x0 length 47
Thu Oct  2 19:55:19 2014 daemon.debug pppd[4355]:  dst
64:70:02:e2:a4:28  src 8c:90:d3:32:21:75
Thu Oct  2 19:55:19 2014 daemon.debug pppd[4355]:  [service-name]
[AC-name WDBGON4838W] [host-uniq  00 00 11 03] [AC-cookie  d1 3f 3a 2c
85 d9 98 51 71 3d eb e0 a8 1c 8a 6f]
Thu Oct  2 19:55:19 2014 daemon.debug pppd[4355]: Send PPPOE Discovery
V1T1 PADR session 0x0 length 32
Thu Oct  2 19:55:19 2014 daemon.debug pppd[4355]:  dst
8c:90:d3:32:21:75  src 64:70:02:e2:a4:28
Thu Oct  2 19:55:19 2014 daemon.debug pppd[4355]:  [service-name]
[host-uniq  00 00 11 03] [AC-cookie  d1 3f 3a 2c 85 d9 98 51 71 3d eb
e0 a8 1c 8a 6f]
Thu Oct  2 19:55:19 2014 daemon.debug pppd[4355]: Recv PPPOE Discovery
V1T1 PADS session 0x3 length 12
Thu Oct  2 19:55:19 2014 daemon.debug pppd[4355]:  dst
64:70:02:e2:a4:28  src 8c:90:d3:32:21:75
Thu Oct  2 19:55:19 2014 daemon.debug pppd[4355]:  [service-name]
[host-uniq  00 00 11 03]
Thu Oct  2 19:55:19 2014 daemon.debug pppd[4355]: PADS: Service-Name: ''
Thu Oct  2 19:55:19 2014 daemon.info pppd[4355]: PPP session is 3
Thu Oct  2 19:55:19 2014 daemon.warn pppd[4355]: Connected to
8c:90:d3:32:21:75 via interface eth0.2
Thu Oct  2 19:55:19 2014 daemon.debug pppd[4355]: using channel 3
Thu Oct  2 19:55:19 2014 daemon.info pppd[4355]: Using interface pppoe-wan
Thu Oct  2 19:55:19 2014 daemon.notice pppd[4355]: Connect: pppoe-wan
<--> eth0.2
Thu Oct  2 19:55:19 2014 daemon.debug pppd[4355]: sent [LCP ConfReq
id=0x1 <mru 1492> <magic 0xd20aeba2>]
Thu Oct  2 19:55:19 2014 daemon.debug pppd[4355]: rcvd [LCP ConfAck
id=0x1 <mru 1492> <magic 0xd20aeba2>]
Thu Oct  2 19:55:22 2014 daemon.debug pppd[4355]: rcvd [LCP ConfReq
id=0x55 <mru 1492> <auth pap> <magic 0x744974a8>]
Thu Oct  2 19:55:22 2014 daemon.debug pppd[4355]: sent [LCP ConfAck
id=0x55 <mru 1492> <auth pap> <magic 0x744974a8>]
Thu Oct  2 19:55:22 2014 daemon.debug pppd[4355]: sent [LCP EchoReq
id=0x0 magic=0xd20aeba2]
Thu Oct  2 19:55:22 2014 daemon.debug pppd[4355]: rcvd [LCP EchoRep
id=0x0 magic=0x744974a8]
Thu Oct  2 19:55:23 2014 daemon.debug pppd[4355]: rcvd [PAP AuthAck id=0x1 ""]
Thu Oct  2 19:55:23 2014 daemon.notice pppd[4355]: PAP authentication succeeded
Thu Oct  2 19:55:23 2014 daemon.notice pppd[4355]: peer from calling
number 8C:90:D3:32:21:75 authorized
Thu Oct  2 19:55:23 2014 daemon.debug pppd[4355]: sent [IPCP ConfReq
id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Thu Oct  2 19:55:23 2014 daemon.debug pppd[4355]: rcvd [IPCP ConfReq
id=0x7a <addr 206.248.154.122>]
Thu Oct  2 19:55:23 2014 daemon.debug pppd[4355]: sent [IPCP ConfAck
id=0x7a <addr 206.248.154.122>]
Thu Oct  2 19:55:23 2014 daemon.debug pppd[4355]: rcvd [IPCP ConfNak
id=0x1 <addr 76.10.167.248> <ms-dns1 206.248.154.22> <ms-dns2
206.248.154.170>]
Thu Oct  2 19:55:23 2014 daemon.debug pppd[4355]: sent [IPCP ConfReq
id=0x2 <addr 76.10.167.248> <ms-dns1 206.248.154.22> <ms-dns2
206.248.154.170>]
Thu Oct  2 19:55:23 2014 daemon.debug pppd[4355]: rcvd [IPCP ConfAck
id=0x2 <addr 76.10.167.248> <ms-dns1 206.248.154.22> <ms-dns2
206.248.154.170>]
Thu Oct  2 19:55:23 2014 daemon.notice pppd[4355]: local  IP address
76.10.167.248
Thu Oct  2 19:55:23 2014 daemon.notice pppd[4355]: remote IP address
206.248.154.122
Thu Oct  2 19:55:23 2014 daemon.notice pppd[4355]: primary   DNS
address 206.248.154.22
Thu Oct  2 19:55:23 2014 daemon.notice pppd[4355]: secondary DNS
address 206.248.154.170
Thu Oct  2 19:55:23 2014 daemon.debug pppd[4355]: Script
/lib/netifd/ppp-up started (pid 4405)
Thu Oct  2 19:55:23 2014 daemon.notice netifd: Network device
'pppoe-wan' link is up
Thu Oct  2 19:55:23 2014 daemon.notice netifd: Interface 'wan' is now up
Thu Oct  2 19:55:23 2014 daemon.debug pppd[4355]: Script
/lib/netifd/ppp-up finished (pid 4405), status = 0x1
Thu Oct  2 19:55:23 2014 user.info syslog: module is already loaded - cls_u32
Thu Oct  2 19:55:23 2014 kern.emerg already loaded - cls_u32
Thu Oct  2 19:55:23 2014 user.info syslog: module is already loaded - em_u32
Thu Oct  2 19:55:23 2014 kern.emerg already loaded - em_u32
Thu Oct  2 19:55:23 2014 user.info syslog: module is already loaded -
act_connmark
Thu Oct  2 19:55:23 2014 kern.emerg already loaded - act_connmark
Thu Oct  2 19:55:23 2014 user.info syslog: module is already loaded - act_mirred
Thu Oct  2 19:55:23 2014 kern.emerg already loaded - act_mirred
Thu Oct  2 19:55:23 2014 user.info syslog: module is already loaded -
sch_ingress
Thu Oct  2 19:55:23 2014 kern.emerg already loaded - sch_ingress
Thu Oct  2 19:55:24 2014 user.info syslog: module is already loaded - cls_fw
Thu Oct  2 19:55:24 2014 kern.emerg already loaded - cls_fw
Thu Oct  2 19:55:24 2014 user.info syslog: module is already loaded - sch_hfsc
Thu Oct  2 19:55:24 2014 kern.emerg already loaded - sch_hfsc
Thu Oct  2 19:55:24 2014 user.notice firewall: Reloading firewall due
to ifup of wan (pppoe-wan)
Thu Oct  2 19:55:25 2014 daemon.notice miniupnpd[2757]: shutting down MiniUPnPd
Thu Oct  2 19:55:25 2014 daemon.err miniupnpd[2757]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:55:25 2014 daemon.err miniupnpd[2757]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:55:25 2014 daemon.err miniupnpd[2757]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:55:25 2014 daemon.err miniupnpd[2757]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:55:25 2014 daemon.err miniupnpd[2757]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:55:25 2014 daemon.err miniupnpd[2757]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:55:25 2014 daemon.err miniupnpd[2757]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:55:25 2014 daemon.err miniupnpd[2757]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:55:25 2014 daemon.err miniupnpd[2757]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:55:25 2014 daemon.err miniupnpd[2757]:
sendto(udp_shutdown=-1): Bad file descriptor
Thu Oct  2 19:55:25 2014 daemon.notice miniupnpd[4610]: HTTP listening
on port 5000
Thu Oct  2 19:55:25 2014 daemon.warn miniupnpd[4610]: no HTTP IPv6
address, disabling IPv6
Thu Oct  2 19:55:28 2014 user.notice netCheck: WAN restart complete,
attempt number: 1 of 6
Thu Oct  2 19:55:45 2014 user.notice hotplug.d: Calling netCheck.sh to
make sure everything is sane...
Thu Oct  2 19:56:01 2014 cron.info crond[966]: crond: user root:
process already running: /bin/sh /etc/netCheck.sh
Thu Oct  2 19:56:37 2014 user.notice netCheck: All tests passed, WAN
appears to be online.
_______________________________________________
openwrt-devel mailing list
openwrt-devel at lists.openwrt.org
https://lists.openwrt.org/cgi-bin/mailman/listinfo/openwrt-devel



More information about the openwrt-devel mailing list