What's new

Time not sequential in log since upgrade to 386.4

  • SNBForums Code of Conduct

    SNBForums is a community for everyone, no matter what their level of experience.

    Please be tolerant and patient of others, especially newcomers. We are all here to share and learn!

    The rules are simple: Be patient, be nice, be helpful or be gone!

Morris

Very Senior Member
I find this rather odd and don't see a reason for it. Device is RT-AX86U. Sample Log with bolded variations:

Jan 10 10:08:03 dnsmasq-dhcp[2992]: DHCPREQUEST(br0) 192.168.2.222 48:8f:5a:c3:fc:ac
Jan 10 10:08:03 dnsmasq-dhcp[2992]: DHCPACK(br0) 192.168.2.222 48:8f:5a:c3:fc:ac MikroTik-CRS305
Jan 10 10:08:32 dnsmasq-dhcp[2992]: DHCPREQUEST(br0) 192.168.2.66 f0:27:2d:a0:70:96
Jan 10 10:08:32 dnsmasq-dhcp[2992]: DHCPACK(br0) 192.168.2.66 f0:27:2d:a0:70:96
Jan 10 10:09:15 dnsmasq-dhcp[2992]: DHCPREQUEST(br0) 192.168.2.40 c8:ff:28:7c:2b:92
Jan 10 10:09:15 dnsmasq-dhcp[2992]: DHCPACK(br0) 192.168.2.40 c8:ff:28:7c:2b:92
Jan 10 10:38:06 dnsmasq-dhcp[2992]: DHCPREQUEST(br0) 192.168.2.3 b4:f7:a1:b3:80:68
Jan 10 10:38:06 dnsmasq-dhcp[2992]: DHCPACK(br0) 192.168.2.3 b4:f7:a1:b3:80:68 android-9782aa618bd2546c
Jan 10 10:56:35 dnsmasq-dhcp[2992]: DHCPREQUEST(br0) 192.168.2.31 ac:67:84:f1:45:50
Jan 10 10:56:35 dnsmasq-dhcp[2992]: DHCPACK(br0) 192.168.2.31 ac:67:84:f1:45:50
Jan 10 16:01:51 kernel: eth4 (Ext switch port: 3) (Logical Port: 11) (phyId: b) Link DOWN.
Jan 10 16:01:51 kernel: br0: port 1(eth4) entered disabled state
Jan 10 16:01:51 kernel: br1: port 2(eth4.501) entered disabled state
Jan 10 16:01:51 kernel: br2: port 2(eth4.502) entered disabled state

Jan 10 11:06:53 wlceventd: wlceventd_proc_event(469): wl0.2: Deauth_ind 04:03:D6:75:85:28, status: 0, reason: Unspecified reason (1)
Jan 10 11:06:53 wlceventd: wlceventd_proc_event(505): wl0.2: Auth 04:03:D6:75:85:28, status: Successful (0)
Jan 10 11:06:53 wlceventd: wlceventd_proc_event(534): wl0.2: Assoc 04:03:D6:75:85:28, status: Successful (0)
Jan 10 11:06:53 hostapd: wl0.2: STA 04:03:d6:75:85:28 IEEE 802.11: associated
Jan 10 11:06:53 hostapd: wl0.2: STA 04:03:d6:75:85:28 RADIUS: starting accounting session 72A78D818A849710
Jan 10 11:06:53 hostapd: wl0.2: STA 04:03:d6:75:85:28 WPA: pairwise key handshake completed (RSN)
Jan 10 11:06:53 dnsmasq-dhcp[2992]: DHCPDISCOVER(br0) 04:03:d6:75:85:28
Jan 10 11:06:53 dnsmasq-dhcp[2992]: DHCPOFFER(br0) 192.168.2.77 04:03:d6:75:85:28
Jan 10 11:06:56 dnsmasq-dhcp[2992]: DHCPDISCOVER(br0) 04:03:d6:75:85:28
Jan 10 11:06:56 dnsmasq-dhcp[2992]: DHCPOFFER(br0) 192.168.2.77 04:03:d6:75:85:28
Jan 10 11:06:56 dnsmasq-dhcp[2992]: DHCPREQUEST(br0) 192.168.2.77 04:03:d6:75:85:28
Jan 10 11:06:56 dnsmasq-dhcp[2992]: DHCPACK(br0) 192.168.2.77 04:03:d6:75:85:28
Jan 10 16:07:05 kernel: wl0: random key value: 7581E8126DB795573C5C00CB1ED479FE652D7542991900D88F4B56BA823FE777
Jan 10 11:07:05 hostapd: wl0.2: STA 04:03:d6:75:85:28 IEEE 802.11: disassociated
Jan 10 11:07:05 wlceventd: wlceventd_proc_event(486): wl0.2: Disassoc 04:03:D6:75:85:28, status: 0, reason: Disassociated because sending station is leaving (or has left) BSS (8)
Jan 10 11:07:05 hostapd: wl0.2: STA 04:03:d6:75:85:28 IEEE 802.11: disassociated
 
Already noted in the beta thread.
Thank you Colin. I would not know about that. Looks like it still needs fixing. Do you know if the time stamp or the sequence is what is correct?
 
From what I can remember I don't think it's something RMerlin considers worth looking into. The kernel messages are in UTC whereas the other messages are in the local time zone.
 
From what I can remember I don't think it's something RMerlin considers worth looking into. The kernel messages are in UTC whereas the other messages are in the local time zone.
Thank you,

Then they are sequential and it's easy to look at if something happens.
 
Same in the factory firmware.
 
I find this rather odd and don't see a reason for it. Device is RT-AX86U. Sample Log with bolded variations:

Jan 10 10:08:03 dnsmasq-dhcp[2992]: DHCPREQUEST(br0) 192.168.2.222 48:8f:5a:c3:fc:ac
Jan 10 10:08:03 dnsmasq-dhcp[2992]: DHCPACK(br0) 192.168.2.222 48:8f:5a:c3:fc:ac MikroTik-CRS305
Jan 10 10:08:32 dnsmasq-dhcp[2992]: DHCPREQUEST(br0) 192.168.2.66 f0:27:2d:a0:70:96
Jan 10 10:08:32 dnsmasq-dhcp[2992]: DHCPACK(br0) 192.168.2.66 f0:27:2d:a0:70:96
Jan 10 10:09:15 dnsmasq-dhcp[2992]: DHCPREQUEST(br0) 192.168.2.40 c8:ff:28:7c:2b:92
Jan 10 10:09:15 dnsmasq-dhcp[2992]: DHCPACK(br0) 192.168.2.40 c8:ff:28:7c:2b:92
Jan 10 10:38:06 dnsmasq-dhcp[2992]: DHCPREQUEST(br0) 192.168.2.3 b4:f7:a1:b3:80:68
Jan 10 10:38:06 dnsmasq-dhcp[2992]: DHCPACK(br0) 192.168.2.3 b4:f7:a1:b3:80:68 android-9782aa618bd2546c
Jan 10 10:56:35 dnsmasq-dhcp[2992]: DHCPREQUEST(br0) 192.168.2.31 ac:67:84:f1:45:50
Jan 10 10:56:35 dnsmasq-dhcp[2992]: DHCPACK(br0) 192.168.2.31 ac:67:84:f1:45:50
Jan 10 16:01:51 kernel: eth4 (Ext switch port: 3) (Logical Port: 11) (phyId: b) Link DOWN.
Jan 10 16:01:51 kernel: br0: port 1(eth4) entered disabled state
Jan 10 16:01:51 kernel: br1: port 2(eth4.501) entered disabled state
Jan 10 16:01:51 kernel: br2: port 2(eth4.502) entered disabled state

Jan 10 11:06:53 wlceventd: wlceventd_proc_event(469): wl0.2: Deauth_ind 04:03:D6:75:85:28, status: 0, reason: Unspecified reason (1)
Jan 10 11:06:53 wlceventd: wlceventd_proc_event(505): wl0.2: Auth 04:03:D6:75:85:28, status: Successful (0)
Jan 10 11:06:53 wlceventd: wlceventd_proc_event(534): wl0.2: Assoc 04:03:D6:75:85:28, status: Successful (0)
Jan 10 11:06:53 hostapd: wl0.2: STA 04:03:d6:75:85:28 IEEE 802.11: associated
Jan 10 11:06:53 hostapd: wl0.2: STA 04:03:d6:75:85:28 RADIUS: starting accounting session 72A78D818A849710
Jan 10 11:06:53 hostapd: wl0.2: STA 04:03:d6:75:85:28 WPA: pairwise key handshake completed (RSN)
Jan 10 11:06:53 dnsmasq-dhcp[2992]: DHCPDISCOVER(br0) 04:03:d6:75:85:28
Jan 10 11:06:53 dnsmasq-dhcp[2992]: DHCPOFFER(br0) 192.168.2.77 04:03:d6:75:85:28
Jan 10 11:06:56 dnsmasq-dhcp[2992]: DHCPDISCOVER(br0) 04:03:d6:75:85:28
Jan 10 11:06:56 dnsmasq-dhcp[2992]: DHCPOFFER(br0) 192.168.2.77 04:03:d6:75:85:28
Jan 10 11:06:56 dnsmasq-dhcp[2992]: DHCPREQUEST(br0) 192.168.2.77 04:03:d6:75:85:28
Jan 10 11:06:56 dnsmasq-dhcp[2992]: DHCPACK(br0) 192.168.2.77 04:03:d6:75:85:28
Jan 10 16:07:05 kernel: wl0: random key value: 7581E8126DB795573C5C00CB1ED479FE652D7542991900D88F4B56BA823FE777
Jan 10 11:07:05 hostapd: wl0.2: STA 04:03:d6:75:85:28 IEEE 802.11: disassociated
Jan 10 11:07:05 wlceventd: wlceventd_proc_event(486): wl0.2: Disassoc 04:03:D6:75:85:28, status: 0, reason: Disassociated because sending station is leaving (or has left) BSS (8)
Jan 10 11:07:05 hostapd: wl0.2: STA 04:03:d6:75:85:28 IEEE 802.11: disassociated
Code:
Version 3.0.0.4.386.46061
2022/01/11 75.31 MBytes
ASUS RT-AX86U Firmware version 3.0.0.4.386.46061

>>> snip <<<
Fixed time zone error.
 
Code:
Version 3.0.0.4.386.46061
2022/01/11 75.31 MBytes
ASUS RT-AX86U Firmware version 3.0.0.4.386.46061

>>> snip <<<
Fixed time zone error.
http://www.snbforums.com/threads/asus-rt-ax86u-firmware-version-3-0-0-4-386-46061-2022-01-11.76716/
http://www.snbforums.com/threads/as...-0-0-4-386-46061-2022-01-11.76716/post-736445

Two useful links for those who want more detail.

A LOT has been fixed after the untested stock firmware for the RT-AX86U was provided to the Maestro.
Great to see - now we must wait patiently for the next Merlin release.

I only hope this time they [Asus] provide stock GPL's that are actually released versions so that Merlin can focus on his wizardry and not be distracted by the alpha and beta glitches which relate to closed source portions of the code over which he has no control. :).
 
"time zone error" could mean anything. I think it's more likely to be an actual time zone problem (of which there are many) they've fixed rather than this kernel timestamp issue. But one can always hope.
 

Latest threads

Sign Up For SNBForums Daily Digest

Get an update of what's new every day delivered to your mailbox. Sign up here!
Top