iwl3945 produces a lot of error messages in syslog

I have same problem.

I too have the same problem!!

OS: Ubuntu hardy 2.6.24-8 (updated Feb, 16)

dmesg output (repeated _many_ times)
[ 4120.788928] wmaster0: CCMP decrypt failed for RX frame from 00:14:c1:xx:xx:xx
[ 4120.792474] wmaster0: CCMP decrypt failed for RX frame from 00:14:c1:xx:xx:xx
....

Driver: iwl4965
filename:
/lib/modules/2.6.24-8-generic/ubuntu/wireless/iwlwifi/iwlwifi/compatible/iwl4965.ko
version: 1.2.0
description: Intel(R) Wireless WiFi Link 4965AGN driver for Linux
srcversion: BFF70BD669F5E9D76F2C9C1

MAC80211:
filename: /lib/modules/2.6.24-8-generic/kernel/net/mac80211/mac80211.ko
description: IEEE 802.11 subsystem
srcversion: C79DCFE79459B0C83D7D85D
depends: cfg80211
vermagic: 2.6.24-8-generic SMP mod_unload 586

Despite this error, however, I can browse internet as usual.

Same here:

Millions of lines like
[104603.005249] wmaster0: TKIP decrypt failed for RX frame from ...

Driver: iwl3945
filename: /lib/modules/2.6.24-8-generic/ubuntu/wireless/iwlwifi/iwlwifi/compatible/iwl3945.ko
license: GPL
author: Copyright(c) 2003-2007 Intel Corporation
version: 1.2.0
description: Intel(R) PRO/Wireless 3945ABG/BG Network Connection driver for Linux
srcversion: 8E95C617988943846696F97

Network is working in principal but when for example copying a file over NFS, it takes a while until the process actually starts and the load of klogd goes up to 100%.
Many applications seem to be affected by this somehow (take long to start, are less responsive).

I am affraid i got exactly the same thing (same wireless card)

Linux bob-laptop 2.6.24-8-generic #1 SMP Thu Feb 14 20:40:45 UTC 2008 i686 GNU/Linux

Feb 22 14:54:16 bob-laptop kernel: [ 2861.727879] eth1: TKIP decrypt failed for RX frame from 00:14:bf:2f:02:91 (res=-3)
Feb 22 14:54:16 bob-laptop kernel: [ 2861.728986] eth1: TKIP decrypt failed for RX frame from 00:14:bf:2f:02:91 (res=-3)
Feb 22 14:54:16 bob-laptop kernel: [ 2861.730335] eth1: TKIP decrypt failed for RX frame from 00:14:bf:2f:02:91 (res=-3)
Feb 22 14:54:16 bob-laptop kernel: [ 2861.731446] eth1: TKIP decrypt failed for RX frame from 00:14:bf:2f:02:91 (res=-3)
Feb 22 14:54:16 bob-laptop kernel: [ 2861.731886] eth1: TKIP decrypt failed for RX frame from 00:14:bf:2f:02:91 (res=-3)
Feb 22 14:54:16 bob-laptop kernel: [ 2861.734004] eth1: TKIP decrypt failed for RX frame from 00:14:bf:2f:02:91 (res=-3)
Feb 22 14:54:16 bob-laptop kernel: [ 2861.734437] eth1: TKIP decrypt failed for RX frame from 00:14:bf:2f:02:91 (res=-3)
Feb 22 14:54:16 bob-laptop kernel: [ 2861.735565] eth1: TKIP decrypt failed for RX frame from 00:14:bf:2f:02:91 (res=-3)
Feb 22 14:54:16 bob-laptop kernel: [ 2861.736260] eth1: TKIP decrypt failed for RX frame from 00:14:bf:2f:02:91 (res=-3)
Feb 22 14:54:16 bob-laptop kernel: [ 2861.737606] eth1: TKIP decrypt failed for RX frame from 00:14:bf:2f:02:91 (res=-3)

Same with

Linux version 2.6.22-14-generic (buildd@terranova) (gcc version 4.1.3 20070929 (prerelease) (Ubuntu 4.1.2-16ubuntu2)) #1 SMP Tue Feb 12 07:42:25 UTC 2008

[64868.312000] wmaster0: TKIP decrypt failed for RX frame from 00:14:6c:89:56:f3 (res=-2)
[64869.376000] wmaster0: TKIP decrypt failed for RX frame from 00:14:6c:89:56:f3 (res=-3)
[64869.416000] wme:wme_qdiscop_enqueue ht_queue=4,queue=2 pool=0xF qdisc=dfa74080
[64875.524000] wme:wme_qdiscop_enqueue ht_queue=4,queue=2 pool=0xF qdisc=dfa74080
[64875.524000] wme:wme_qdiscop_enqueue ht_queue=4,queue=2 pool=0xF qdisc=dfa74080
[64875.524000] wme:wme_qdiscop_enqueue ht_queue=4,queue=2 pool=0xF qdisc=dfa74080
[64875.716000] wmaster0: TKIP decrypt failed for RX frame from 00:14:6c:89:56:f3 (res=-3)

(iwl4965 here)

I think I'm repeating myself here:

Please stop the "me too" messages, they just add noise.

This seems odd - after poking around the web, I found this link: http://<email address hidden>/msg29450.html
It's a patch that only logs these errors when CONFIG_MAC80211_DEBUG is enabled.
I checked the kernel source (in /usr/src/linux-source-2.6.24/net/mac80211/wpa.c) and verified that the patch is indeed applied to the source - the ifdef statements are there. However, when I look in /boot/config-2.6.24-8-generic to check the kernel config, I see "# CONFIG_MAC80211_DEBUG is not set". The only place the string "TKIP decrypt failed" occurs in the kernel tree is within that ifdef in wpa.c, but according to the kernel config, the variable is not set, so the logging shouldn't occur. Unless I'm missing something with the way ubuntu kernel builds work? Maybe there's a patch that removes the ifdefs?

I could be way off base - just trying to help..

Well, me message wasn't actually a "me too". I was pointing out that the same problem also occurs with _4965_ chipsets on _gutsy's_ kernel.

BTW: my router is a box running hostap, I configured hostapd to use CCMP rather than TKIP, which eliminates the symptom from my T61p's iwl4965.

But not from iwl3945: l-u-m-2.6.24-10.14 problem still here (but as already mentioned: not causing problems).

Hi,

This seems to be the cause of some random apparent lockups that I've had. If I wait long enough then the system responds again but there are hundreds of logged errors.

Chris

Same here:

$ lspci
0c:00.0 Network controller: Intel Corporation PRO/Wireless 3945ABG Network Connection (rev 02)

$ lsmod
iwl3945
iwlwifi_mac80211

$ dmesg
[ 6099.549190] wmaster0: TKIP decrypt failed for RX frame from 00:40:10:10:00:02 (res=-3)
[ 6099.554293] wmaster0: TKIP decrypt failed for RX frame from 00:40:10:10:00:02 (res=-3)
[ 6099.560401] wmaster0: TKIP decrypt failed for RX frame from 00:40:10:10:00:02 (res=-3)
[ 6099.566526] wmaster0: TKIP decrypt failed for RX frame from 00:40:10:10:00:02 (res=-3)
[ 6099.571313] wmaster0: TKIP decrypt failed for RX frame from 00:40:10:10:00:02 (res=-3)
[ 6099.571404] wmaster0: TKIP decrypt failed for RX frame from 00:40:10:10:00:02 (res=-3)
[ 6099.571931] wmaster0: TKIP decrypt failed for RX frame from 00:40:10:10:00:02 (res=-3)
[ 6099.577989] wmaster0: TKIP decrypt failed for RX frame from 00:40:10:10:00:02 (res=-3)
...

Used net_ratelimit() to slow down the occurrence of these messages in syslog. They will still appear because of incoming traffic in your environment, but will no longer flood syslog.

Does not satisfy SRU criteria.

> They will still appear because of incoming traffic in your environment, but will no longer flood syslog.

So does this mean that the drivers for other devices on the same network link that don't post these messages are broken?

Just a tip - if you need to clear out the logs once they've filled up your root partition, here's how:

cd /var/log/
/etc/init.d/sysklogd stop
sed -i '/TKIP decrypt/d' kern.log* syslog* debug*
/etc/init.d/sysklogd start

After a quick look at the source it looks like the iwlwifi driver handles TKIP (and WEP) decryption in hardware but the softmac stack tries again to do it in software, even if the necessary flags are set. What don't I understand is why the softmac stack doesn't drop the packet as it should...

Is the version of mac80211 in linux-ubuntu-modules (iwlwifi_mac80211) slightly incompatible with the iwlwifi driver shipped in the same package? I'll take a look at upgrading both.

This bug was fixed in the package linux-ubuntu-modules-2.6.24 - 2.6.24-11.15

---------------
linux-ubuntu-modules-2.6.24 (2.6.24-11.15) hardy; urgency=low

  [Tim Gardner]

  * Fix ATI HDMI oops
    - LP: #196026
  * ifdef and net_ratelimit() iwlwifi debug messages
    - LP: #190475
  * SAUCE: Implemented suspend quirk support for HP NC6220 and NW8240
    - LP: #151111
  * Removed ivtv driver
    - LP: #197089

 -- Tim Gardner <email address hidden> Thu, 28 Feb 2008 13:53:20 -0700

I can confirm that linux-ubuntu-modules-2.6.24-11.15 solves the issue.

The 2.6.24-11 update fixes the bug for me too.

Indeed, checked on my laptop (iwl3945) with 2.6.24-11 and this fixes the bug for me also.

Bug re-appeared with 2.6.24-16. See https://bugs.launchpad.net/ubuntu/+source/linux-ubuntu-modules-2.6.24/+bug/40763/comments/25.

Hi Captain Haddock,

From the other bug report and comment you referenced it looks like you are using the ipw2200 driver which is different from the iwl3945 driver which this bug report is about. Also, the messages you are seeing look different than what was reported here. I'm going to remark this bug as "Fix Released" as it appears you are experiencing a different bug using a different driver. I'll follow up with you at the other bug 40763 . Thanks.

This problem doesn't seem fixed on Hardy's kernel 2.6.24-22-generic and linux-ubuntu-modules-2.6.24-22-generic. Or maybe it's not exactly the same one and I should file a new bug ?

[colin@marv ~]$ uname -a
Linux marv 2.6.24-22-generic #1 SMP Mon Nov 24 18:32:42 UTC 2008 i686 GNU/Linux

[colin@marv ~]$ lsmod|grep iwl
iwl3945 96244 0
lbm_iwl_mac80211 242420 1 iwl3945
rfkill 8596 2 iwl3945
led_class 6020 1 iwl3945
lbm_iwl_cfg80211 33248 2 iwl3945,lbm_iwl_mac80211

[colin@marv ~]$ modinfo iwl3945
filename: /lib/modules/2.6.24-22-generic/updates/iwl3945.ko
license: GPL
author: Copyright(c) 2003-2008 Intel Corporation
version: 1.2.26k
description: Intel(R) PRO/Wireless 3945ABG/BG Network Connection driver for Linux

[colin@marv ~]$ lspci|grep 3945
0c:00.0 Network controller: Intel Corporation PRO/Wireless 3945ABG Network Connection (rev 02)

[colin@marv ~]$ lspci -n|grep 0c:00.0
0c:00.0 0280: 8086:4222 (rev 02)

[colin@marv ~]$ dmesg|tail
[63849.613408] wlan0: TKIP decrypt failed for RX frame from 00:40:f4:f5:ac:54 (res=-3)
[63850.158169] wlan0: TKIP decrypt failed for RX frame from 00:40:f4:f5:ac:54 (res=-3)
[63850.714111] wmaster0: RX protected frame, but have no key
[63850.773643] wlan0: TKIP decrypt failed for RX frame from 00:40:f4:f5:ac:54 (res=-3)
[63925.858473] wlan0: TKIP decrypt failed for RX frame from 00:40:f4:f5:ac:54 (res=-3)
[63925.945234] wlan0: TKIP decrypt failed for RX frame from 00:40:f4:f5:ac:54 (res=-3)
[63926.216256] wmaster0: RX protected frame, but have no key
[63995.817713] wmaster0: RX protected frame, but have no key
[63996.668264] wlan0: TKIP decrypt failed for RX frame from 00:40:f4:f5:ac:54 (res=-3)
[63996.850377] wlan0: TKIP decrypt failed for RX frame from 00:40:f4:f5:ac:54 (res=-3)

I'm observing the previous behaviour of excessive logging with iwl4965 from linux-backports-modules-2.6.24-24-generic (2.6.24-24.32)