Modify

Opened 3 years ago

Closed 3 years ago

Last modified 3 years ago

#19144 closed defect (invalid)

r44651 unstable, several problems (lantiq/Buffalo WBMR-HP-G300H)

Reported by: juanriccio@… Owned by: developers
Priority: normal Milestone: Chaos Calmer 15.05
Component: packages Version: Trunk
Keywords: Cc:

Description

Several stability problems not present in r43143. Absolutely the same configuration.

1) Load average jumped from ~1.72 to ~3.5-4.0
2) System log: daemon.err uhttpd[2079]: sh: write error: Broken pipe
3) Main overview page in LuCI won't update ("collecting data")
4) ddns doesn't work, wget fails (it does work in r43143)
5) WAN (DSL) disconnects randomly, approximately every 15-20 hours. It takes a longer than usual time to reconnect.

Maybe I'd better make separate tickets? I think all these issues are connected, so I won't spam the system unless some admin/expert advises me to. I will gladly perform any suggested tests.

I am enclosing an excerpt of my system log.

Attachments (1)

system-log_r44651.txt (3.4 KB) - added by anonymous 3 years ago.
system log excerpt

Download all attachments as: .zip

Change History (22)

Changed 3 years ago by anonymous

system log excerpt

comment:1 follow-up: Changed 3 years ago by finas

exactly the same issues with my WBMR-HP-G300H using trunk build from this monday.

comment:2 in reply to: ↑ 1 Changed 3 years ago by hnyman

Replying to finas:

exactly the same issues with my WBMR-HP-G300H using trunk build from this monday.

Do you have the exactly same ddns-specific errors in the log?

juanriccio seems to have no.ip.com ddns module installed, which is causing errors.

user.err ddns-scripts[2967]: no_ip_com_org: Busybox Wget Error: '1'

And there are other ddns errors like

can't open '/var/run/ddns/lucihelper.dat': No such file or directory

Do the broken pipe errors materialise also after disabling/stopping ddns?

I notified the ddns author about the possible errors. Hopefully he reacts
https://github.com/openwrt/packages/pull/862#issuecomment-78279782

Like I said in https://dev.openwrt.org/ticket/19083#comment:17 and https://dev.openwrt.org/ticket/19083#comment:13 , you really need to try to identify the problematic module. You with the errors are the ones that can easiest identify the problematic application. There is probably no need to compile anything, but stopping and/disabling services might lead into analysis of the source.

"/etc/init.d/ddns stop" stops the service
while "/etc/init.d/ddns disable" will prevent it from starting again (until you "enable" it).

comment:3 Changed 3 years ago by finas

ddns is not the source of the problem as I have it also with no-ip module and stoping it wont solve the issues ( high load average, luci overview page not refreshing well ) dsl disconnects and dsl_control status takes about 10 minutes to output data.

comment:4 Changed 3 years ago by anonymous

Can you check the reported bogomips in dmesg?

comment:5 Changed 3 years ago by juanriccio@…

I had already ruled out ddns too, after heeding hnyman's advice about stopping and disabling the service.

The broken pipe errors in the system log appear to be caused by visiting the LuCI ddns page, even if the service's stopped (and disabled).

I've just made another test - on r44683 now.

Things haven't improved - even worsened. System load is still quite high and the leds are not working correctly: POWER led blinks during boot, DSL led seems to work fine, but WiFi led is off even with wireless running.

Any other services I could try stopping/disabling? How can I post a list of the active services?

Here's my system log if it helps.

Wed Mar 11 19:09:50 2015 user.emerg syslog: Another app is currently holding the xtables lock. Perhaps you want to use the -w option?
Wed Mar 11 19:09:50 2015 user.emerg syslog: Another app is currently holding the xtables lock. Perhaps you want to use the -w option?
Wed Mar 11 19:09:50 2015 user.emerg syslog: Another app is currently holding the xtables lock. Perhaps you want to use the -w option?
Wed Mar 11 19:09:50 2015 user.emerg syslog: Another app is currently holding the xtables lock. Perhaps you want to use the -w option?
Wed Mar 11 19:09:50 2015 user.emerg syslog: Another app is currently holding the xtables lock. Perhaps you want to use the -w option?
Wed Mar 11 19:09:55 2015 daemon.err insmod: module is already loaded - cls_u32
Wed Mar 11 19:09:55 2015 daemon.err insmod: module is already loaded - em_u32
Wed Mar 11 19:09:55 2015 daemon.err insmod: module is already loaded - act_connmark
Wed Mar 11 19:09:55 2015 daemon.err insmod: module is already loaded - act_mirred
Wed Mar 11 19:09:55 2015 daemon.err insmod: module is already loaded - sch_ingress
Wed Mar 11 19:09:55 2015 daemon.err insmod: module is already loaded - cls_fw
Wed Mar 11 19:09:55 2015 daemon.err insmod: module is already loaded - sch_hfsc
Wed Mar 11 19:09:56 2015 daemon.err insmod: module is already loaded - xt_multiport
Wed Mar 11 19:09:56 2015 daemon.err insmod: module is already loaded - xt_length
Wed Mar 11 19:09:58 2015 daemon.info dnsmasq[1799]: started, version 2.72 cachesize 150
Wed Mar 11 19:09:58 2015 daemon.info dnsmasq[1799]: 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
Wed Mar 11 19:09:58 2015 daemon.info dnsmasq-dhcp[1799]: DHCP, IP range 192.168.1.1 -- 192.168.1.49, lease time 12h
Wed Mar 11 19:09:58 2015 daemon.info dnsmasq-dhcp[1799]: DHCP, IP range 192.168.2.50 -- 192.168.2.149, lease time 2h
Wed Mar 11 19:09:58 2015 daemon.info dnsmasq-dhcp[1799]: DHCP, IP range 192.168.3.100 -- 192.168.3.199, lease time 1d
Wed Mar 11 19:09:58 2015 daemon.info dnsmasq[1799]: using local addresses only for domain lan
Wed Mar 11 19:09:58 2015 daemon.warn dnsmasq[1799]: no servers found in /tmp/resolv.conf.auto, will retry
Wed Mar 11 19:09:58 2015 daemon.info dnsmasq[1799]: read /etc/hosts - 29 addresses
Wed Mar 11 19:09:58 2015 daemon.info dnsmasq[1799]: read /tmp/hosts/dhcp - 10 addresses
Wed Mar 11 19:09:58 2015 daemon.info dnsmasq-dhcp[1799]: read /etc/ethers - 0 addresses
Wed Mar 11 19:09:59 2015 user.notice upnp daemon: external interface not found, not starting
Wed Mar 11 19:10:03 2015 user.notice firewall: Reloading firewall due to ifup of lan (br-lan)
Wed Mar 11 19:10:05 2015 daemon.warn pppd[1423]: Timeout waiting for PADO packets
Wed Mar 11 19:10:05 2015 daemon.err pppd[1423]: Unable to complete PPPoE Discovery
Wed Mar 11 19:10:05 2015 daemon.info pppd[1423]: Exit.
Wed Mar 11 19:10:05 2015 daemon.notice netifd: Interface 'wan' is now down
Wed Mar 11 19:10:05 2015 daemon.notice netifd: Interface 'wan' is disabled
Wed Mar 11 19:10:05 2015 daemon.notice netifd: Interface 'wan' is enabled
Wed Mar 11 19:10:05 2015 daemon.notice netifd: Interface 'wan' is setting up now
Wed Mar 11 19:10:06 2015 daemon.info pppd[1967]: Plugin rp-pppoe.so loaded.
Wed Mar 11 19:10:06 2015 daemon.info pppd[1967]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Wed Mar 11 19:10:06 2015 daemon.notice pppd[1967]: pppd 2.4.7 started by root, uid 0
Wed Mar 11 19:10:07 2015 user.emerg syslog: configfile: stat (/etc/collectd/conf.d) failed: No such file or directory
Wed Mar 11 19:10:07 2015 user.emerg syslog: plugin_load: Could not find plugin "iptables" in /usr/lib/collectd
Wed Mar 11 19:10:07 2015 user.emerg syslog: plugin_load: Could not find plugin "conntrack" in /usr/lib/collectd
Wed Mar 11 19:10:07 2015 user.emerg syslog: plugin_load: Could not find plugin "tcpconns" in /usr/lib/collectd
Wed Mar 11 19:10:07 2015 user.emerg syslog: Found a configuration for the `tcpconns' plugin, but the plugin isn't loaded or didn't register a configuration callback.
Wed Mar 11 19:10:07 2015 user.emerg syslog: Found a configuration for the `tcpconns' plugin, but the plugin isn't loaded or didn't register a configuration callback.
Wed Mar 11 19:10:07 2015 user.emerg syslog: Found a configuration for the `tcpconns' plugin, but the plugin isn't loaded or didn't register a configuration callback.
Wed Mar 11 19:10:08 2015 user.emerg syslog: rrdtool plugin: RRASingle = true: creating only AVERAGE RRAs
Wed Mar 11 19:10:08 2015 user.emerg syslog: plugin_load: Could not find plugin "processes" in /usr/lib/collectd
Wed Mar 11 19:10:08 2015 user.emerg syslog: Found a configuration for the `processes' plugin, but the plugin isn't loaded or didn't register a configuration callback.
Wed Mar 11 19:10:08 2015 user.emerg syslog: Found a configuration for the `processes' plugin, but the plugin isn't loaded or didn't register a configuration callback.
Wed Mar 11 19:10:08 2015 user.emerg syslog: Found a configuration for the `processes' plugin, but the plugin isn't loaded or didn't register a configuration callback.
Wed Mar 11 19:10:08 2015 user.emerg syslog: plugin_load: Could not find plugin "olsrd" in /usr/lib/collectd
Wed Mar 11 19:10:08 2015 user.emerg syslog: Found a configuration for the `olsrd' plugin, but the plugin isn't loaded or didn't register a configuration callback.
Wed Mar 11 19:10:08 2015 user.emerg syslog: Found a configuration for the `olsrd' plugin, but the plugin isn't loaded or didn't register a configuration callback.
Wed Mar 11 19:10:08 2015 user.emerg syslog: plugin_load: Could not find plugin "memory" in /usr/lib/collectd
Wed Mar 11 19:10:08 2015 user.emerg syslog: plugin_load: Could not find plugin "cpu" in /usr/lib/collectd
Wed Mar 11 19:10:09 2015 user.emerg syslog: setting up led wifi
Wed Mar 11 19:10:09 2015 user.emerg syslog: Skipping trigger 'phy0tpt' for led 'wifi' due to missing kernel module
Wed Mar 11 19:10:09 2015 user.emerg syslog: setting up led usb
Wed Mar 11 19:10:09 2015 user.emerg syslog: setting up led dsl
Wed Mar 11 19:10:09 2015 user.emerg syslog: setting up led movie
Wed Mar 11 19:10:09 2015 user.emerg syslog: setting up led online
Wed Mar 11 19:10:09 2015 user.emerg syslog: setting up led online2
Wed Mar 11 19:10:09 2015 user.emerg syslog: setting up led power2
Wed Mar 11 19:10:09 2015 user.emerg syslog: setting up led security
Wed Mar 11 19:10:09 2015 user.emerg syslog: setting up led power
Wed Mar 11 19:10:10 2015 user.notice upnp daemon: external interface not found, not starting
Wed Mar 11 19:10:10 2015 daemon.info procd: - init complete -
Wed Mar 11 19:10:12 2015 user.notice firewall: Reloading firewall due to ifup of service (br-service)
Wed Mar 11 19:10:21 2015 daemon.warn pppd[1967]: Timeout waiting for PADO packets
Wed Mar 11 19:10:21 2015 daemon.err pppd[1967]: Unable to complete PPPoE Discovery
Wed Mar 11 19:10:21 2015 daemon.info pppd[1967]: Exit.
Wed Mar 11 19:10:21 2015 daemon.notice netifd: Interface 'wan' is now down
Wed Mar 11 19:10:21 2015 daemon.notice netifd: Interface 'wan' is disabled
Wed Mar 11 19:10:21 2015 daemon.notice netifd: Interface 'wan' is enabled
Wed Mar 11 19:10:21 2015 daemon.notice netifd: Interface 'wan' is setting up now
Wed Mar 11 19:10:22 2015 daemon.info pppd[2354]: Plugin rp-pppoe.so loaded.
Wed Mar 11 19:10:22 2015 daemon.info pppd[2354]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Wed Mar 11 19:10:22 2015 daemon.notice pppd[2354]: pppd 2.4.7 started by root, uid 0
Wed Mar 11 19:10:37 2015 daemon.warn pppd[2354]: Timeout waiting for PADO packets
Wed Mar 11 19:10:37 2015 daemon.err pppd[2354]: Unable to complete PPPoE Discovery
Wed Mar 11 19:10:37 2015 daemon.info pppd[2354]: Exit.
Wed Mar 11 19:10:37 2015 daemon.notice netifd: Interface 'wan' is now down
Wed Mar 11 19:10:37 2015 daemon.notice netifd: Interface 'wan' is disabled
Wed Mar 11 19:10:37 2015 daemon.notice netifd: Interface 'wan' is enabled
Wed Mar 11 19:10:37 2015 daemon.notice netifd: Interface 'wan' is setting up now
Wed Mar 11 19:10:37 2015 daemon.info pppd[2369]: Plugin rp-pppoe.so loaded.
Wed Mar 11 19:10:37 2015 daemon.info pppd[2369]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Wed Mar 11 19:10:37 2015 daemon.notice pppd[2369]: pppd 2.4.7 started by root, uid 0
Wed Mar 11 19:10:52 2015 daemon.warn pppd[2369]: Timeout waiting for PADO packets
Wed Mar 11 19:10:52 2015 daemon.err pppd[2369]: Unable to complete PPPoE Discovery
Wed Mar 11 19:10:52 2015 daemon.info pppd[2369]: Exit.
Wed Mar 11 19:10:52 2015 daemon.notice netifd: Interface 'wan' is now down
Wed Mar 11 19:10:52 2015 daemon.notice netifd: Interface 'wan' is disabled
Wed Mar 11 19:10:52 2015 daemon.notice netifd: Interface 'wan' is enabled
Wed Mar 11 19:10:52 2015 daemon.notice netifd: Interface 'wan' is setting up now
Wed Mar 11 19:10:52 2015 daemon.info pppd[2384]: Plugin rp-pppoe.so loaded.
Wed Mar 11 19:10:52 2015 daemon.info pppd[2384]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Wed Mar 11 19:10:52 2015 daemon.notice pppd[2384]: pppd 2.4.7 started by root, uid 0
Wed Mar 11 19:11:07 2015 daemon.warn pppd[2384]: Timeout waiting for PADO packets
Wed Mar 11 19:11:07 2015 daemon.err pppd[2384]: Unable to complete PPPoE Discovery
Wed Mar 11 19:11:07 2015 daemon.info pppd[2384]: Exit.
Wed Mar 11 19:11:07 2015 daemon.notice netifd: Interface 'wan' is now down
Wed Mar 11 19:11:07 2015 daemon.notice netifd: Interface 'wan' is disabled
Wed Mar 11 19:11:07 2015 daemon.notice netifd: Interface 'wan' is enabled
Wed Mar 11 19:11:07 2015 daemon.notice netifd: Interface 'wan' is setting up now
Wed Mar 11 19:11:08 2015 daemon.info pppd[2399]: Plugin rp-pppoe.so loaded.
Wed Mar 11 19:11:08 2015 daemon.info pppd[2399]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Wed Mar 11 19:11:08 2015 daemon.notice pppd[2399]: pppd 2.4.7 started by root, uid 0
Wed Mar 11 19:11:23 2015 daemon.warn pppd[2399]: Timeout waiting for PADO packets
Wed Mar 11 19:11:23 2015 daemon.err pppd[2399]: Unable to complete PPPoE Discovery
Wed Mar 11 19:11:23 2015 daemon.info pppd[2399]: Exit.
Wed Mar 11 19:11:23 2015 daemon.notice netifd: Interface 'wan' is now down
Wed Mar 11 19:11:23 2015 daemon.notice netifd: Interface 'wan' is disabled
Wed Mar 11 19:11:23 2015 daemon.notice netifd: Interface 'wan' is enabled
Wed Mar 11 19:11:23 2015 daemon.notice netifd: Interface 'wan' is setting up now
Wed Mar 11 19:11:23 2015 daemon.info pppd[2414]: Plugin rp-pppoe.so loaded.
Wed Mar 11 19:11:23 2015 daemon.info pppd[2414]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Wed Mar 11 19:11:23 2015 daemon.notice pppd[2414]: pppd 2.4.7 started by root, uid 0
Wed Mar 11 19:11:38 2015 daemon.warn pppd[2414]: Timeout waiting for PADO packets
Wed Mar 11 19:11:38 2015 daemon.err pppd[2414]: Unable to complete PPPoE Discovery
Wed Mar 11 19:11:38 2015 daemon.info pppd[2414]: Exit.
Wed Mar 11 19:11:38 2015 daemon.notice netifd: Interface 'wan' is now down
Wed Mar 11 19:11:38 2015 daemon.notice netifd: Interface 'wan' is disabled
Wed Mar 11 19:11:38 2015 daemon.notice netifd: Interface 'wan' is enabled
Wed Mar 11 19:11:38 2015 daemon.notice netifd: Interface 'wan' is setting up now
Wed Mar 11 19:11:38 2015 daemon.info pppd[2431]: Plugin rp-pppoe.so loaded.
Wed Mar 11 19:11:38 2015 daemon.info pppd[2431]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Wed Mar 11 19:11:38 2015 daemon.notice pppd[2431]: pppd 2.4.7 started by root, uid 0
Wed Mar 11 19:11:53 2015 daemon.warn pppd[2431]: Timeout waiting for PADO packets
Wed Mar 11 19:11:53 2015 daemon.err pppd[2431]: Unable to complete PPPoE Discovery
Wed Mar 11 19:11:53 2015 daemon.info pppd[2431]: Exit.
Wed Mar 11 19:11:54 2015 daemon.notice netifd: Interface 'wan' is now down
Wed Mar 11 19:11:54 2015 daemon.notice netifd: Interface 'wan' is disabled
Wed Mar 11 19:11:54 2015 daemon.notice netifd: Interface 'wan' is enabled
Wed Mar 11 19:11:54 2015 daemon.notice netifd: Interface 'wan' is setting up now
Wed Mar 11 19:11:54 2015 daemon.info pppd[2446]: Plugin rp-pppoe.so loaded.
Wed Mar 11 19:11:54 2015 daemon.info pppd[2446]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Wed Mar 11 19:11:54 2015 daemon.notice pppd[2446]: pppd 2.4.7 started by root, uid 0
Wed Mar 11 19:12:09 2015 daemon.warn pppd[2446]: Timeout waiting for PADO packets
Wed Mar 11 19:12:09 2015 daemon.err pppd[2446]: Unable to complete PPPoE Discovery
Wed Mar 11 19:12:09 2015 daemon.info pppd[2446]: Exit.
Wed Mar 11 19:12:09 2015 daemon.notice netifd: Interface 'wan' is now down
Wed Mar 11 19:12:09 2015 daemon.notice netifd: Interface 'wan' is disabled
Wed Mar 11 19:12:09 2015 daemon.notice netifd: Interface 'wan' is enabled
Wed Mar 11 19:12:09 2015 daemon.notice netifd: Interface 'wan' is setting up now
Wed Mar 11 19:12:09 2015 daemon.info pppd[2465]: Plugin rp-pppoe.so loaded.
Wed Mar 11 19:12:09 2015 daemon.info pppd[2465]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Wed Mar 11 19:12:09 2015 daemon.notice pppd[2465]: pppd 2.4.7 started by root, uid 0
Wed Mar 11 19:12:24 2015 daemon.warn pppd[2465]: Timeout waiting for PADO packets
Wed Mar 11 19:12:24 2015 daemon.err pppd[2465]: Unable to complete PPPoE Discovery
Wed Mar 11 19:12:24 2015 daemon.info pppd[2465]: Exit.
Wed Mar 11 19:12:24 2015 daemon.notice netifd: Interface 'wan' is now down
Wed Mar 11 19:12:24 2015 daemon.notice netifd: Interface 'wan' is disabled
Wed Mar 11 19:12:24 2015 daemon.notice netifd: Interface 'wan' is enabled
Wed Mar 11 19:12:24 2015 daemon.notice netifd: Interface 'wan' is setting up now
Wed Mar 11 19:12:24 2015 kern.err kernel: [  194.096000] [DSL_BSP_Showtime 894]: Datarate US intl = 477647, fast = 0
Wed Mar 11 19:12:24 2015 kern.warn kernel: [  194.100000] enter showtime, cell rate: 0 - 1126, 1 - 1126, xdata addr: 0x82e20000
Wed Mar 11 19:12:25 2015 daemon.info pppd[2521]: Plugin rp-pppoe.so loaded.
Wed Mar 11 19:12:25 2015 daemon.info pppd[2521]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.7
Wed Mar 11 19:12:25 2015 daemon.notice pppd[2521]: pppd 2.4.7 started by root, uid 0
Wed Mar 11 19:12:30 2015 daemon.info pppd[2521]: PPP session is 4454
Wed Mar 11 19:12:30 2015 daemon.warn pppd[2521]: Connected to 00:90:1a:a4:5a:03 via interface nas0
Wed Mar 11 19:12:30 2015 kern.info kernel: [  199.532000] pppoe-wan: renamed from ppp0
Wed Mar 11 19:12:30 2015 daemon.info pppd[2521]: Using interface pppoe-wan
Wed Mar 11 19:12:30 2015 daemon.notice pppd[2521]: Connect: pppoe-wan <--> nas0
Wed Mar 11 19:12:30 2015 daemon.notice pppd[2521]: PAP authentication succeeded
Wed Mar 11 19:12:30 2015 daemon.notice pppd[2521]: peer from calling number 00:90:1A:A4:5A:03 authorized
Wed Mar 11 19:12:31 2015 daemon.notice pppd[2521]: local  IP address 87.20.138.254
Wed Mar 11 19:12:31 2015 daemon.notice pppd[2521]: remote IP address 192.168.100.1
Wed Mar 11 19:12:31 2015 daemon.notice pppd[2521]: primary   DNS address 85.37.17.11
Wed Mar 11 19:12:31 2015 daemon.notice pppd[2521]: secondary DNS address 85.38.28.69
Wed Mar 11 19:12:31 2015 daemon.notice netifd: Network device 'pppoe-wan' link is up
Wed Mar 11 19:12:31 2015 daemon.notice netifd: Interface 'wan' is now up
Wed Mar 11 19:12:31 2015 daemon.info dnsmasq[1799]: read /etc/hosts - 29 addresses
Wed Mar 11 19:12:31 2015 daemon.info dnsmasq[1799]: read /tmp/hosts/odhcpd - 0 addresses
Wed Mar 11 19:12:31 2015 daemon.info dnsmasq[1799]: read /tmp/hosts/dhcp - 10 addresses
Wed Mar 11 19:12:31 2015 daemon.info dnsmasq-dhcp[1799]: read /etc/ethers - 0 addresses
Wed Mar 11 19:12:32 2015 daemon.err insmod: module is already loaded - cls_u32
Wed Mar 11 19:12:32 2015 daemon.err insmod: module is already loaded - em_u32
Wed Mar 11 19:12:32 2015 daemon.err insmod: module is already loaded - act_connmark
Wed Mar 11 19:12:32 2015 daemon.err insmod: module is already loaded - act_mirred
Wed Mar 11 19:12:32 2015 daemon.err insmod: module is already loaded - sch_ingress
Wed Mar 11 19:12:32 2015 daemon.err insmod: module is already loaded - cls_fw
Wed Mar 11 19:12:32 2015 daemon.err insmod: module is already loaded - sch_hfsc
Wed Mar 11 19:12:33 2015 daemon.info dnsmasq[1799]: reading /tmp/resolv.conf.auto
Wed Mar 11 19:12:33 2015 daemon.info dnsmasq[1799]: using local addresses only for domain lan
Wed Mar 11 19:12:33 2015 daemon.info dnsmasq[1799]: using nameserver 8.8.4.4#53
Wed Mar 11 19:12:33 2015 daemon.info dnsmasq[1799]: using nameserver 8.8.8.8#53
Wed Mar 11 19:12:33 2015 user.notice firewall: Reloading firewall due to ifup of wan (pppoe-wan)
Wed Mar 11 19:12:35 2015 daemon.info dnsmasq[1799]: exiting on receipt of SIGTERM
Wed Mar 11 19:12:35 2015 daemon.info dnsmasq[2714]: started, version 2.72 cachesize 150
Wed Mar 11 19:12:35 2015 daemon.info dnsmasq[2714]: 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
Wed Mar 11 19:12:35 2015 daemon.info dnsmasq-dhcp[2714]: DHCP, IP range 192.168.1.1 -- 192.168.1.49, lease time 12h
Wed Mar 11 19:12:35 2015 daemon.info dnsmasq-dhcp[2714]: DHCP, IP range 192.168.2.50 -- 192.168.2.149, lease time 2h
Wed Mar 11 19:12:35 2015 daemon.info dnsmasq-dhcp[2714]: DHCP, IP range 192.168.3.100 -- 192.168.3.199, lease time 1d
Wed Mar 11 19:12:35 2015 daemon.info dnsmasq[2714]: using local addresses only for domain lan
Wed Mar 11 19:12:35 2015 daemon.info dnsmasq[2714]: reading /tmp/resolv.conf.auto
Wed Mar 11 19:12:35 2015 daemon.info dnsmasq[2714]: using local addresses only for domain lan
Wed Mar 11 19:12:35 2015 daemon.info dnsmasq[2714]: using nameserver 8.8.4.4#53
Wed Mar 11 19:12:35 2015 daemon.info dnsmasq[2714]: using nameserver 8.8.8.8#53
Wed Mar 11 19:12:35 2015 daemon.info dnsmasq[2714]: read /etc/hosts - 29 addresses
Wed Mar 11 19:12:35 2015 daemon.info dnsmasq[2714]: read /tmp/hosts/dhcp - 10 addresses
Wed Mar 11 19:12:35 2015 daemon.info dnsmasq[2714]: read /tmp/hosts/odhcpd - 0 addresses
Wed Mar 11 19:12:35 2015 daemon.info dnsmasq-dhcp[2714]: read /etc/ethers - 0 addresses
Wed Mar 11 19:12:36 2015 daemon.notice miniupnpd[2737]: HTTP listening on port 5000
Wed Mar 11 19:12:36 2015 daemon.notice miniupnpd[2737]: HTTP IPv6 address given to control points : [fd6a:384f:d726:0:224:a5ff:febd:4796]
Wed Mar 11 19:12:36 2015 daemon.notice miniupnpd[2737]: Listening for NAT-PMP/PCP traffic on port 5351
Wed Mar 11 20:12:05 2015 daemon.err miniupnpd[2737]: upnp_event_recv: recv(): Connection reset by peer
Wed Mar 11 20:12:05 2015 daemon.info pppd[2521]: System time change detected.

[...] REBOOT


comment:6 Changed 3 years ago by anonymous

I nailed this down a bit more:

problem is somewhere between r44130 and r44346

CHAOS CALMER (Bleeding Edge, r44346)
root@router:~# uptime
01:00:58 up 8 min, load average: 2.42, 1.33, 0.62
root@router:~# uname -a
Linux router 3.14.32 #2 SMP Thu Mar 12 00:49:01 WET 2015 mips GNU/Linux

CHAOS CALMER (Bleeding Edge, r44130)
root@router:~# uptime
00:38:14 up 7 min, load average: 0.24, 0.44, 0.26
root@router:~# uname -a
Linux router 3.14.28 #2 SMP Wed Mar 11 23:16:13 WET 2015 mips GNU/Linux

Both builds use the lastest package feeds.

comment:7 Changed 3 years ago by anonymous

Stable build
CHAOS CALMER r43143 / LuCI (git-15.041.27918-86c6272)

root@OpenWrt-main:~# uptime
05:10:10 up 8:34, load average: 1.81, 1.72, 1.70
root@OpenWrt-main:~# uname -a
Linux OpenWrt-main 3.14.18 #2 Tue Feb 17 13:33:34 CET 2015 mips GNU/Linux
root@OpenWrt-main:~# dmesg | grep -i bogomips
[ 0.040000] Calibrating delay loop... 221.18 BogoMIPS (lpj=442368)

I'll check the oldest unstable build I can find when I get some time to flash, test, reflash back.

comment:8 Changed 3 years ago by finas

nailed a bit more:

problem is somewhere between r44301 and r44346

CHAOS CALMER (Bleeding Edge, r44346)
root@router:~# uptime
01:00:58 up 8 min, load average: 2.42, 1.33, 0.62
root@router:~# uname -a
Linux router 3.14.32 #2 SMP Thu Mar 12 00:49:01 WET 2015 mips GNU/Linux

CHAOS CALMER (Bleeding Edge, r44301)
root@router:~# uptime
08:06:15 up 5 min, load average: 0.51, 0.59, 0.28
root@router:~# uname -a
Linux router 3.14.30 #2 SMP Thu Mar 12 02:11:09 WET 2015 mips GNU/Linux

44301 works perfectly but 44346 does not. will try to bissec this a bit more.

comment:9 Changed 3 years ago by hnyman

r44301 - r44346 is narrow enough period to look at individual changes:
Log of all checkins in main repo: https://dev.openwrt.org/log/?rev=44346
Diff of actual changes 44301-44346: https://dev.openwrt.org/changeset?reponame=&new=44346@%2F&old=44301@%2F

You are on lantiq platform, so you can safely ignore anything related to ar71xx, au1000, etc. But you need to check lantiq changes, kernel, generic, base-files etc. etc.

There are two lantiq-specific changes:
https://dev.openwrt.org/changeset/44346/
https://dev.openwrt.org/changeset/44320/

44346 is actually my favorite as the culprit. It makes dsl driver changes targeting kernel 3.18.

You should also test with r44348, as kernel was bumped to 3.18 there and that is a rather heavy checkin. (44346 is between 3.14 and 3.18, as drivers were already patched for 3.18 while kernel was 3.14, so it might be fundamentally unstable)

comment:10 Changed 3 years ago by finas

hnyman: thanks for the tips.

tried 44320, works well, so problem is between 44320 and 44346

CHAOS CALMER (Bleeding Edge, r44320)
root@router:~# uptime
12:19:34 up 8 min, load average: 0.10, 0.38, 0.26
Linux router 3.14.32 #2 SMP Thu Mar 12 09:12:33 WET 2015 mips GNU/Linux
root@router:~#

comment:11 follow-up: Changed 3 years ago by juanriccio@…

Checking out r44346 for some more testing, I don't know how to check out the appropriate version of the feeds using git (as in feeds.conf.default) - I can only do that using svn, which is slightly deprecated from what I read.

Sorry for the newbie question: how do I edit a line such as the following in feeds.conf.default so that I get the snapshot at the time of r44346?

src-git packages https://github.com/openwrt/packages.git

comment:12 Changed 3 years ago by finas

found the offending commit. Thanks for the tip hnyman. it's 44346. tested 44345 and it works perfectly. 44346 doesn't work well and all the others I have tried after that one, including a bunch of them with kernel 3.18 also exibit the same problems.

CHAOS CALMER (Bleeding Edge, r44345)
root@router:~# uptime
14:07:18 up 7 min, load average: 0.08, 0.19, 0.20
root@router:~# uname -a
Linux router 3.14.32 #2 SMP Thu Mar 12 13:31:39 WET 2015 mips GNU/Linux

juanriccio: all the tests I made where with latest feeds, so as to not increase the number of variables.

comment:13 Changed 3 years ago by juanriccio@…

hnyman: Your help was highly appreciated, here and in another partially related ticket thread. Thanks!

finas: I thought feeds were a fundamental part of the revision/expected behaviour, so I took the trouble of trying to restore past feeds and recreate an exact snapshot because I thought I would _decrease_ the number of variables. Is that wrong? (Trying to learn for the future). Congrats on your terrific detective work :)

comment:14 in reply to: ↑ 11 Changed 3 years ago by hnyman

Great that the offending commit was found. But you still need to get the developers' attention to fix it...

I think that it would be better to check out the feeds from the same moment, as some changes in recent feeds may require something new in the main svn repo. So, using new feeds with old main code may cause additional problems.

Replying to juanriccio@…:

Sorry for the newbie question: how do I edit a line such as the following in feeds.conf.default so that I get the snapshot at the time of r44346?

You can checkout manually a certain git commit or use ^hash "caret" syntax in feed.conf.default to specify the hash of the revision. See example for "oldpackages" at http://git.openwrt.org/?p=14.07/openwrt.git;a=blob;f=feeds.conf.default;h=8e7579df992434345c58c9832b783685f18c9ae1;hb=f7bea41ba912768c42a724f55e55fc2b87d1c81a

My community build at the forum contains also a "time machine" script for just that purpose. Key functionality is below and explains how to use the datetime as the uniform version specifier for both svn and git:

# versionT  -  Update source code to revision T and then build
#              T argument: date as yyyy-mm-dd or "yyyy-mm-dd hh:mm"
#              first "git pull --depth=500" to deepen git history (shallow)
#              use "git checkout master" for each feed to get back to HEAD

svn up -r {"$1"}
(cd feeds/luci ; git checkout `git rev-list -n 1 --before="$1" master`)
(cd feeds/packages ; git checkout `git rev-list -n 1 --before="$1" master`)
(cd feeds/routing ; git checkout `git rev-list -n 1 --before="$1" master`)

During the years I have done so much debugging that I created the script to ease it.

comment:15 Changed 3 years ago by anonymous

how do we get the developers attention?

comment:16 Changed 3 years ago by anonymous

hnyman: thanks, noted for next time.

anonymous: I opened a ticket about this a few days ago, but I asked for it to be closed because I thought it was my mistake. /ticket/19127.html
I haven't reopened it, but I added a comment pointing to this thread. I'm not sure about reopening it and causing a duplicate.

comment:17 Changed 3 years ago by finas

maybe you can reopen the ticket, this way the devs will notice it :)

comment:18 Changed 3 years ago by finas

yes, reopening would not be good. I'm sure they will notice this ticket.

comment:19 Changed 3 years ago by nbd

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

Having many different issues in one ticket makes things very hard to track of, which is why I'm closing this one.

Please open up individual tickets for issues that you found. Make sure you look for a matching old ticket for each issue instead of opening up a duplicate one.

For new tickets that you open, please make sure you include all relevant information that you've found already.

comment:20 Changed 3 years ago by finas

opened ticket
/ticket/19192.html

comment:21 Changed 3 years ago by nbd

dsl driver stability fix committed in r44844, r44845

Add Comment

Modify Ticket

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


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

 
Note: See TracTickets for help on using tickets.