Wireless Access

Reply
Frequent Contributor I
Posts: 61
Registered: ‎01-18-2012

Kernel message with incrementing numbers

Hello,

 

We recently upgraded our M3 controller to AOS 6.4.2.6 and I noticed that one AP is showing in the system logs with incrementing numbers:

 

Apr 23 10:09:24  KERNEL(AP_NAME@192.168.66.74): [67950.222672]
Apr 23 10:09:52  KERNEL(AP_NAME@192.168.66.74): [67977.569164]
Apr 23 10:10:06  KERNEL(AP_NAME@192.168.66.74): [67991.913480]
Apr 23 10:10:12  KERNEL(AP_NAME@192.168.66.74): [67998.456512]
Apr 23 10:10:21  KERNEL(AP_NAME@192.168.66.74): [68007.348325]
Apr 23 10:10:43  KERNEL(AP_NAME@192.168.66.74): [68028.815591]
Apr 23 10:10:45  KERNEL(AP_NAME@192.168.66.74): [68031.339407]
Apr 23 10:10:54  KERNEL(AP_NAME@192.168.66.74): [68040.482872]
Apr 23 10:12:46  KERNEL(AP_NAME@192.168.66.74): [68151.546531]
Apr 23 10:13:00  KERNEL(AP_NAME@192.168.66.74): [68165.974742]
Apr 23 10:13:31  KERNEL(AP_NAME@192.168.66.74): [68196.807312]
Apr 23 10:15:05  KERNEL(AP_NAME@192.168.66.74): [68290.963298]
Apr 23 10:15:33  KERNEL(AP_NAME@192.168.66.74): [68319.316412]
Apr 23 10:15:51  KERNEL(AP_NAME@192.168.66.74): [68336.596698]
Apr 23 10:15:53  KERNEL(AP_NAME@192.168.66.74): [68339.197131]
Apr 23 10:18:00  KERNEL(AP_NAME@192.168.66.74): [68466.282819]

 

As anybody seen this before?

 

show ap debug crash-info ap-name returns nothing and AP is live and working.

 

Thanks

Moderator
Posts: 321
Registered: ‎08-28-2009

Re: Kernel message with incrementing numbers

[ Edited ]

Yann

I think you may have chopped the end of the message, the number that is incrementing is a timestamp - there should be stuff after it, example:

 

Apr 23 01:07:24  KERNEL(ap225-sales@10.74.32.131): [149815.906120] <64:76:ba:ae:2f:7e> [wlc_dotxstatus@40810]:sent data packet dcae8900, seqnum 0x568, pkttag->seq = 0x568, was_acked 1, supr_status 0
Apr 23 01:07:24  KERNEL(ap225-sales@10.74.32.131): [149816.061422] <64:76:ba:ae:2f:7e> [wlc_dotxstatus@40810]:sent data packet dcae8900, seqnum 0x568, pkttag->seq = 0x568, was_acked 1, supr_status 0
Apr 23 15:28:31  KERNEL(ap225-sales@10.74.32.131): [201483.270693] chan dur      ibss           obss           interf       time
Apr 23 15:28:31  KERNEL(ap225-sales@10.74.32.131): [201483.353060] 161 1002    4  0% Low     139 13% Medium 8305 828% High   201480
Apr 23 15:28:31  KERNEL(ap225-sales@10.74.32.131): [201483.438514] 161 1000    9  0% Low      55  5% Low      21  2% Low    201479
Apr 23 15:28:31  KERNEL(ap225-sales@10.74.32.131): [201483.522918] 161 1000    8  0% Low      80  8% Low      24  2% Low    201478

 

It appears R&D has decided to start sending the ap console log messages from the AP to the controller into the system log. I am trying to find out if this is really what they wanted to do as it's going to create consternation for customers and these messages come with zero information outside of R&D - will update when I learn something, hopefully in next 48 hours.

 

I should add - these messages are probably just informational, despite some often scary sounding language - please post a snapshot of them here so we can try to make a judgement if you need a TAC case too. You can also find these logs in "show ap debug log ap-name <>"

 

regards

-jeff

Frequent Contributor I
Posts: 61
Registered: ‎01-18-2012

Re: Kernel message with incrementing numbers

Hi jgoff,

 

I wish I could say that the messages have been truncated but what I've posted is exactly what I got except for the ap name. I did notice however that every once in a while  - 100/full would be added.

 

Apr 25 03:04:17  KERNEL(AP_NAME@192.168.66.74): [215242.192121]
Apr 25 03:07:27  KERNEL(AP_NAME@192.168.66.74): [215432.562999]  - 100/Full
Apr 25 03:08:14  KERNEL(AP_NAME@192.168.66.74): [215479.670385]
Apr 25 03:09:42  KERNEL(AP_NAME@192.168.66.74): [215567.162382]
Apr 25 03:09:52  KERNEL(AP_NAME@192.168.66.74): [215577.648007]
Apr 25 03:12:46  KERNEL(AP_NAME@192.168.66.74): [215751.289836]
Apr 25 03:12:53  KERNEL(AP_NAME@192.168.66.74): [215758.587833]
Apr 25 03:13:10  KERNEL(AP_NAME@192.168.66.74): [215774.795215]  - 100/Full
Apr 25 03:13:58  KERNEL(AP_NAME@192.168.66.74): [215822.843693]

 

Sometimes it's hours between those tidbits of information.

 

Thank you for looking into this.

Moderator
Posts: 321
Registered: ‎08-28-2009

Re: Kernel message with incrementing numbers

hi Yann

you might be able to see the full message using "show ap debug log ap-name <>", can you try to see ? At least 2 new messages were added to 6.4.2.6 that seem to have an incorrect priority on them, hence they are being spammed to the system log - but your case may be different.

 

see if you can get the full output from the ap debug log, there may be something else at play here

 

regards

-jeff

Frequent Contributor I
Posts: 61
Registered: ‎01-18-2012

Re: Kernel message with incrementing numbers

Hi jgoff,

 

The only thing different in the ap debug log is two lines far apart :

 

Apr 27 05:58:40 sapd[2008]: <404069> <WARN> |AP AP_NAME@10.254.254.3 sapd|  ^[bssid 18:64:72:65:65:40] [min_amc_channel 11] [arm_nii_arm_nccii 112] [ap_amc_channel 1] [arm_nccii_arm_nii 142] [channel 11] [new_tx_power 7] [arm_tci 10]

 

Apr 27 08:50:10 sapd[2008]: <404075> <WARN> |AP AP_NAME@10.254.254.3 sapd|  ^[bssid 18:64:72:65:65:40] [arm_ci 11] [arm_nci 1] [current_tx_power 7] [current_channel 11] [current_tx_power_2 6]

Moderator
Posts: 321
Registered: ‎08-28-2009

Re: Kernel message with incrementing numbers

Yann

Seems the IP you are checking is different now - not sure if that was intentional ? At any rate, the log may only exist for a short time, you also need to check "show ap debug driver-log ap-name<>" as well. Wait for the message to re-appear and recollect both as close as possible.

regards

-jeff

Frequent Contributor I
Posts: 61
Registered: ‎01-18-2012

Re: Kernel message with incrementing numbers

Hi jgoff,

 

The IP is different because that was the VPN IP, instead of the local IP

 

The driver log shows a lot more information and provides insight as to what is actually happening.

 

[411983.833079] PHY: eth0 (mdio@ffe24000:00) - Link is Up - 100/Full
[411983.941073] bonding: bond0: link status definitely up for interface eth0.
[411984.023459] bonding: bond0: making interface eth0 the new active one.
[411984.689091] PHY: eth0 (mdio@ffe24000:00) - Link is Down
[411984.901075] bonding: bond0: link status definitely down for interface eth0, disabling it
[411984.999076] bonding: bond0: making interface eth1 the new active one.
[411986.504834] PHY: eth0 (mdio@ffe24000:00) - Link is Up - 100/Full
[411986.677071] bonding: bond0: link status definitely up for interface eth0.
[411986.759414] bonding: bond0: making interface eth0 the new active one.
[411987.373425] PHY: eth0 (mdio@ffe24000:00) - Link is Down
[411987.637074] bonding: bond0: link status definitely down for interface eth0, disabling it
[411987.735047] bonding: bond0: making interface eth1 the new active one.
[411989.335953] PHY: eth0 (mdio@ffe24000:00) - Link is Up - 100/Full
[411989.413564] bonding: bond0: link status definitely up for interface eth0.
[411989.495912] bonding: bond0: making interface eth0 the new active one.
[411990.225496] PHY: eth0 (mdio@ffe24000:00) - Link is Down
[411990.373569] bonding: bond0: link status definitely down for interface eth0, disabling it
[411990.471550] bonding: bond0: making interface eth1 the new active one.
[411992.515716] PHY: eth0 (mdio@ffe24000:00) - Link is Up - 100/Full
[411992.589657] bonding: bond0: link status definitely up for interface eth0.
[411992.672030] bonding: bond0: making interface eth0 the new active one.
[411993.413119] PHY: eth0 (mdio@ffe24000:00) - Link is Down
[411993.549664] bonding: bond0: link status definitely down for interface eth0, disabling it
[411993.625107] stats > 100: ccastats_us: 2392497, acc->statss_ms: 2354
[411993.647741] bonding: bond0: making interface eth1 the new active one.

Search Airheads
Showing results for 
Search instead for 
Did you mean: