Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Wed, Nov 17, 2021 at 07:53:44PM +0100, Stefan Sperling wrote: > I don't see where and how this could happen, but this seems to be where > this bug is hiding. Multicast frames are also never encrypted, so they > would never even trigger any attempt to use a key. Sorry, I was not making much sense here because I confused management with broadcast/multicast frames in my mind. We do not encrypt management frames, but multicast frames will be encrypted with a group key. So the use of encryption in this interrupt handler is legit. The group key should be from one of the two addresses you've identified, and the bogus key address you've seen is something else. I wonder if this bogus address corresponds to >ic_bss->ni_pairwise_key or >ni_pairwise_key of some associated client?
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Wed, Nov 17, 2021 at 03:25:36PM +, Mikolaj Kucharski wrote: > What is strange, I would imagine, that address of they key is one > between those two: > > > $ grep -w ic_def_txkey panic.txt | cut -f3- -d: | tail > ieee80211_setkeysdone() [ieee80211_proto.c|480] case 0 ic_def_txkey > modified, kid=2, k=0x8009cfc8 > ieee80211_setkeysdone() [ieee80211_proto.c|480] case 0 ic_def_txkey > modified, kid=1, k=0x8009cf00 > ieee80211_setkeysdone() [ieee80211_proto.c|480] case 0 ic_def_txkey > modified, kid=2, k=0x8009cfc8 > ieee80211_setkeysdone() [ieee80211_proto.c|480] case 0 ic_def_txkey > modified, kid=1, k=0x8009cf00 > ieee80211_setkeysdone() [ieee80211_proto.c|480] case 0 ic_def_txkey > modified, kid=2, k=0x8009cfc8 > ieee80211_setkeysdone() [ieee80211_proto.c|480] case 0 ic_def_txkey > modified, kid=1, k=0x8009cf00 > ieee80211_setkeysdone() [ieee80211_proto.c|480] case 0 ic_def_txkey > modified, kid=2, k=0x8009cfc8 > ieee80211_setkeysdone() [ieee80211_proto.c|480] case 0 ic_def_txkey > modified, kid=1, k=0x8009cf00 > ieee80211_setkeysdone() [ieee80211_proto.c|480] case 0 ic_def_txkey > modified, kid=2, k=0x8009cfc8 > ieee80211_setkeysdone() [ieee80211_proto.c|480] case 0 ic_def_txkey > modified, kid=1, k=0x8009cf00 > > However just before panic we see this: > > $ sed -ne '/^2027.123448.498681Z/,/^2027.123448.561466Z/p' panic.txt > 2027.123448.498681Z: MMM: ieee80211_clear_htcaps() > [ieee80211_node.c|2328] memset() v25 > 2027.123448.503936Z: MMM: ar5008_tx() [ar5008.c|1527] > 2027.123448.506663Z: MMM: ar5008_tx() [ar5008.c|1530]: key unset for sw > crypto: 0 > 2027.123448.513071Z: MMM: ieee80211_encrypt() [ieee80211_crypto.c|262]: > k: 0x8000225a6708 > 2027.123448.518301Z: MMM: ieee80211_encrypt() [ieee80211_crypto.c|263]: > k_id: 0x0 > 2027.123448.523580Z: MMM: ieee80211_encrypt() [ieee80211_crypto.c|264]: > k_flags: 0x0 > 2027.123448.530034Z: MMM: ieee80211_encrypt() [ieee80211_crypto.c|265]: > k_len: 0x0 > 2027.123448.535279Z: MMM: ieee80211_encrypt() [ieee80211_crypto.c|266]: > k_cipher: 0x0 > 2027.123448.540526Z: MMM: ieee80211_encrypt() [ieee80211_crypto.c|267]: > k_key: 0x > 2027.123448.552314Z: panic: ieee80211_encrypt: key unset for sw crypto: > id=0 cipher=0 flags=0x0 > 2027.123448.561466Z: Stopped at db_enter+0x10: popq%rbp > > What I did not expect is k=0x8009cfc8 and k=0x8009cf00 > between kid=2 and kid=1 and during panic k=0x8000225a6708. I don't > know from where 0x8000225a6708 came from. > Sorry, need to investigate this more. I made a misake of vs k in my debug code :/ -- Regards, Mikolaj
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Wed, Nov 17, 2021 at 03:25:36PM +, Mikolaj Kucharski wrote:
> On Mon, Nov 15, 2021 at 12:33:09PM +, Mikolaj Kucharski wrote:
> > I have more panics, with couple of minutes gap between
> > ieee80211_setkeysdone() from ieee80211_proto.c and panic
> > in ieee80211_encrypt() from ieee80211_crypto.c.
> >
> > Sorry for wrapped lines, but I added Time::HiRes in a rush,
> > the console grabbing script.
> >
>
> Improved console grabbing script, and also added address where the key
> is stored via printf()'s %p. This is full boot up with more debugging.
> I've added printf()'s all but one for memset()'s in net80211/. Not sure
> is full diff interesting here.
>
> What is strange, I would imagine, that address of they key is one
> between those two:
I still cannot make conclusive sense of this.
Your debug log lacks some information:
The node state everywhere a ieee80211_node *ni is involved.
Add this to printf calls to show this: "%d", ni->ni_state
The MAC address everywhere a ieee80211_node *ni is involved.
Add this to printf calls to show the MAC: "%s", ether_sprintf(ni->ni_macaddr)
(Note that you can only use one ether_sprintf() call per printf() call
because ether_sprintf() uses a static buffer.)
Everywhere you see a 'wh', please print whether
IEEE80211_IS_MULTICAST(wh->i_addr1) is true or false.
> 2027.123448.498681Z: MMM: ieee80211_clear_htcaps()
> [ieee80211_node.c|2328] memset() v25
This probably implies a node has left the network.
But it is unclear which node, since we don't see its MAC address.
This might be related to the crash, or it might not.
If this is happening in the call path I believe it is, then we are clearing
ni_pairwise_key at this point, which could explain why you see a key with all
zeros in your debug log.
However, this does not really make sense for another reason, because the
crash happens in a code path which should only be processing multicast
frames, not unicast (more below).
> 2027.123448.503936Z: MMM: ar5008_tx() [ar5008.c|1527]
> 2027.123448.506663Z: MMM: ar5008_tx() [ar5008.c|1530]: key unset for sw
> crypto: 0
> 2027.123448.513071Z: MMM: ieee80211_encrypt() [ieee80211_crypto.c|262]:
> k: 0x8000225a6708
> 2027.123448.518301Z: MMM: ieee80211_encrypt() [ieee80211_crypto.c|263]:
> k_id: 0x0
> 2027.123448.523580Z: MMM: ieee80211_encrypt() [ieee80211_crypto.c|264]:
> k_flags: 0x0
> 2027.123448.530034Z: MMM: ieee80211_encrypt() [ieee80211_crypto.c|265]:
> k_len: 0x0
> 2027.123448.535279Z: MMM: ieee80211_encrypt() [ieee80211_crypto.c|266]:
> k_cipher: 0x0
> 2027.123448.540526Z: MMM: ieee80211_encrypt() [ieee80211_crypto.c|267]:
> k_key: 0x
> 2027.123448.552314Z: panic: ieee80211_encrypt: key unset for sw crypto:
> id=0 cipher=0 flags=0x0
> 2027.123448.561466Z: Stopped at db_enter+0x10: popq%rbp
>
> What I did not expect is k=0x8009cfc8 and k=0x8009cf00
> between kid=2 and kid=1 and during panic k=0x8000225a6708. I don't
> know from where 0x8000225a6708 came from.
This probably means the key being used is not the group key. Does the
unexpected address correspond to the memory address of any ni->ni_parwise_key?
And what is the MAC address of this node?
And what is ni->ni_state of this node?
Now taking look at the back trace:
> 2027.123448.728657Z: *cpu0: ieee80211_encrypt: key unset for sw crypto:
> id=0 cipher=0 flags=0x0
> 2027.123448.735068Z: ddb{0}>
> 2027.123448.735652Z:
> 2027.123448.735864Z: trace
> 2027.123448.742778Z: db_enter() at db_enter+0x10
> 2027.123448.747944Z: panic(81e99dc5) at panic+0xbf
> 2027.123448.753069Z:
> ieee80211_encrypt(8009c048,fd80ca4f4d00,80d2d1c0) at
> ieee80211_encrypt+0x21d
> 2027.123448.763317Z:
> ar5008_tx(8009c000,fd80ca4f4d00,80d2d000,0) at
> ar5008_tx+0x1e7
> 2027.123448.769802Z: athn_start(8009c048) at athn_start+0x108
> 2027.123448.777576Z: ar5008_intr(8009c000) at ar5008_intr+0x216
Here we are in the interrupt handler of athn(4).
The queue of power-saved frames being processed here should only contain
multicast cast frames, not unicast.
If these are multicast frames then a group key should be used, and you
would see one of the expected key two addresses.
If that is not true then we have a bug where a unicast frame is enqueued on
ic->ic_bss->ni_saveqd (the AP) instead of an ni->ni_savedq which represents
an associated station.
I don't see where and how this could happen, but this seems to be where
this bug is hiding. Multicast frames are also never encrypted, so they
would never even trigger any attempt to use a key. Only unicast frames
could trigger encryption, but they should not appear when the interrupt
handler sends frames buffered in ic->ic_bss->ni_savedq because this
queue is supposed to contain multicast frames only!!!
Another possibility is that
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
I have more panics, with couple of minutes gap between
ieee80211_setkeysdone() from ieee80211_proto.c and panic
in ieee80211_encrypt() from ieee80211_crypto.c.
Sorry for wrapped lines, but I added Time::HiRes in a rush,
the console grabbing script.
2025.100422.505898Z: MMM: ieee80211_setkeysdone() [ie
2025.100422.509617Z: ee80211_proto.c|478] case 0 ic_d
2025.100422.514646Z: ef_txkey modified, kid=1
2025.101422.795265Z: MMM: ieee80211_setkeysdone() [ie
2025.101422.797748Z: ee80211_proto.c|478] case 0 ic_d
2025.101422.802819Z: ef_txkey modified, kid=2
2025.102422.848460Z: MMM: ieee80211_setkeysdone() [ie
2025.102422.850955Z: ee80211_proto.c|478] case 0 ic_d
2025.102422.856249Z: ef_txkey modified, kid=1
2025.102808.208425Z: MMM: ar5008_tx() [ar5008.c|1527]
2025.102808.210902Z:
2025.102808.23Z: MMM: ar5008_tx() [ar5008.c|153
2025.102808.213753Z: 0]: key unset for sw crypto: 0
2025.102808.216256Z: MMM: ieee80211_encrypt() [ieee80
2025.102808.220014Z: 211_crypto.c|278]: k_id: 0x0
2025.102808.220209Z: MM
2025.102808.222697Z: M: ieee80211_encrypt() [ieee8021
2025.102808.225240Z: 1_crypto.c|279]: k_flags: 0x0
2025.102808.225432Z: M
2025.102808.227965Z: MM: ieee80211_encrypt() [ieee802
2025.102808.230494Z: 11_crypto.c|280]: k_len: 0x0
2025.102808.230688Z: MM
2025.102808.233198Z: M: ieee80211_encrypt() [ieee8021
2025.102808.237003Z: 1_crypto.c|281]: k_cipher: 0x0
2025.102808.239697Z: MMM: ieee80211_encrypt() [ieee80
2025.102808.242241Z: 211_crypto.c|282]: k_key: 0x
2025.102808.244862Z:
2025.102808.247484Z:
2025.102808.247701Z: pa
2025.102808.251455Z: nic: ieee80211_encrypt: key unse
2025.102808.253992Z: t for sw crypto: id=0 cipher=0 f
2025.102808.257874Z: lags=0x0
2025.102808.258082Z: Stopped at db_ent
2025.102808.260586Z: er+0x10: popq%rbp
2025.102808.260821Z: TID
2025.102808.263206Z:PIDUID PRFLAGS PF
2025.102808.268250Z: LAGS CPU COMMAND
2025.102808.268458Z: db_enter() a
2025.102808.272210Z: t db_enter+0x10
2025.102808.272424Z: panic(8
2025.102808.277336Z: 1ea5c64) at panic+0xbf
2025.102808.277579Z: ieee8021
2025.102808.279966Z: 1_encrypt(8009c048,f
2025.102808.282488Z: d80cfe72900,80ca51c0) at
2025.102808.21Z: ieee80
2025.102808.289080Z: 211_encrypt+0x473
2025.102808.289213Z: ar50
2025.102808.291614Z: 08_tx(8009c000,fd80c
2025.102808.295377Z: fe72900,80ca5000,0) at a
2025.102808.299236Z: r5008_tx+0x
2025.102808.299444Z: 1e7
2025.102808.299575Z: athn_start(fff
2025.102808.302005Z: f8009c048) at athn_start+0x1
2025.102808.307016Z: 08
2025.102808.307225Z: ar5008_intr(8009c000
2025.102808.310961Z: ) at ar5008_intr+0x216
2025.102808.311176Z: intr_han
2025.102808.314831Z: dler(8000225a6c50,80
2025.102808.319896Z: 08f780) at intr_handler+0x6e
2025.102808.320109Z: Xi
2025.102808.323842Z: ntr_ioapic_level3_untramp() at X
2025.102808.326381Z: intr_ioapic_level3_untramp+0x193
2025.102808.331482Z:
2025.102808.331664Z: acpicpu_idle() at acpicpu_idle
2025.102808.335460Z: +0x11f
2025.102808.335689Z: sched_idle(82166
2025.102808.339334Z: ff0) at sched_idle+0x27e
2025.102808.339556Z: end tr
2025.102808.341948Z: ace frame: 0x0, count: 5
2025.102808.342152Z: https:
2025.102808.345907Z: //www.openbsd.org/ddb.html descr
2025.102808.348382Z: ibes the minimum info required i
2025.102808.350979Z: n bug
2025.102808.351159Z: reports. Insufficient in
2025.102808.354957Z: fo makes it difficult to find an
2025.102808.358755Z: d fix bugs.
2025.102808.358969Z: ddb{0}>
--
Regards,
Mikolaj
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Mon, Sep 27, 2021 at 08:39:48AM +, Mikolaj Kucharski wrote:
> On Sat, Sep 25, 2021 at 10:25:12AM +0200, Stefan Sperling wrote:
> > On Sat, Sep 25, 2021 at 02:03:40AM +, Mikolaj Kucharski wrote:
> > > I've added more info, probably mainly for myself. I'm not sure where to
> > > go with this information yet.
> >
> > We need to figure out what makes this code use a group key which
> > has been cleared.
> >
> > Please add printfs for lines of code which modify ic->ic_def_txkey.
> > There's one in ieee80211_setkeysdone() which might be particularly
> > relevant. It is called from the group key renewal timeout which
> > triggers once per hour. Can you reproduce the issue more quickly if
> > you change the 3600s timeout in ieee80211_gtk_rekey_timeout() to
> > a smaller amount of time, say every 60s?
>
> Hm.. my serial console logging doesn't have timestamps, so I'm not
> sure when last `ieee80211_setkeysdone() [ieee80211_proto.c|479]`
> happened, before the panic(). Need to spend more time on it.
...
Stefan, does below output with timestamps help? Timestamps are generated
via Perl's Time::HiRes.
Looking at 20211003.162929.130404Z and 20211003.162929.257441Z it seems
it could be related?
20211003.154928.905775Z: MMM: ieee80211_setkeysdone() [ieee80211_proto.c|479]
ic_def_txkey modified
20211003.155928.964789Z: MMM: ieee80211_setkeysdone() [ieee80211_proto.c|479]
ic_def_txkey modified
20211003.160929.024966Z: MMM: ieee80211_setkeysdone() [ieee80211_proto.c|479]
ic_def_txkey modified
20211003.161929.073949Z: MMM: ieee80211_setkeysdone() [ieee80211_proto.c|479]
ic_def_txkey modified
20211003.162929.130404Z: MMM: ieee80211_setkeysdone() [ieee80211_proto.c|479]
ic_def_txkey modified
20211003.162929.257441Z: MMM: ar5008_tx() [ar5008.c|1521]
20211003.162929.257788Z: MMM: ar5008_tx() [ar5008.c|1524]: key unset for sw
crypto: 0
20211003.162929.257945Z: MMM: ieee80211_encrypt() [ieee80211_crypto.c|278]:
k_id: 0
20211003.162929.258153Z: MMM: ieee80211_encrypt() [ieee80211_crypto.c|279]:
k_flags: 0
20211003.162929.258306Z: MMM: ieee80211_encrypt() [ieee80211_crypto.c|280]:
k_len: 0
20211003.162929.258434Z: MMM: ieee80211_encrypt() [ieee80211_crypto.c|281]:
k_cipher: 0
20211003.162929.258582Z: MMM: ieee80211_encrypt() [ieee80211_crypto.c|282]:
k_key: 0x
20211003.162929.258734Z: panic: ieee80211_encrypt: key unset for sw
20211003.162929.319438Z: crypto: id=0 cipher=0 flags=0x0
20211003.162929.319780Z: Stopped at db_enter+0x10: popq%rbp
20211003.162929.319942Z: TIDPIDUID PRFLAGS PFLAGS CPU
COMMAND
20211003.162929.320095Z: db_enter() at db_enter+0x10
20211003.162929.320244Z: panic(81ea9632) at panic+0xbf
20211003.162929.320374Z:
ieee80211_encrypt(8009c048,fd80c6ca2900,80c971c0) at ieee80
20211003.162929.320504Z: 211_encrypt+0x473
20211003.162929.320655Z:
ar5008_tx(8009c000,fd80c6ca2900,80c97000,0) at ar5008_tx+0x
20211003.162929.320805Z: 1e7
20211003.162929.320932Z: athn_start(8009c048) at athn_start+0x108
20211003.162929.321058Z: ar5008_intr(8009c000) at ar5008_intr+0x216
20211003.162929.321271Z: intr_handler(fff
20211003.162929.367310Z: f8000225a6190,8008f780) at intr_handler+0x6e
20211003.162929.367625Z: Xintr_ioapic_level3_untramp() at
Xintr_ioapic_level3_untramp+0x193
20211003.162929.367809Z: acpicpu_idle() at acpicpu_idle+0x11f
20211003.162929.368014Z: sched_idle(821a2ff0) at sched_idle+0x27e
20211003.162929.368175Z: end trace frame: 0x0, count: 5
20211003.162929.368299Z: https://www.openbsd.org/ddb.html describes the minimum
info required in bug
20211003.162929.368424Z: reports. Insufficient info makes it difficult to find
and fix bugs.
20211003.162929.368571Z: ddb{0}>
Full serial console log with timestamps:
20211003.131916.244815Z: OpenBSD 7.0-current (GENERIC.MP) #5: Sat Sep 25
21:40:37 UTC 2021
20211003.131916.244939Z:
r...@pc1.home.local:/home/mkucharski/openbsd/src/sys/arch/amd64/compile/GENERIC.MP
20211003.131916.245063Z: real mem = 4259872768 (4062MB)
20211003.131916.245186Z: avail mem = 4114731008 (3924MB)
20211003.131916.245343Z: random: good seed from bootblocks
20211003.131916.245498Z: mpath0 at root
20211003.131916.245633Z: scsibus0 at mpath0: 256 targets
20211003.131916.292074Z: mainbus0 at root
20211003.131916.292396Z: bios0 at mainbus0: SMBIOS rev. 3.0 @ 0xcfe8b040 (13
entries)
20211003.131916.292545Z: bios0: vendor coreboot version "v4.12.0.4" date
08/27/2020
20211003.131916.292689Z: bios0: PC Engines apu2
20211003.131916.292833Z: acpi0 at bios0: ACPI 6.0
20211003.131916.345119Z:
20211003.131916.345432Z: acpi0: sleep states S0 S1 S4 S5
20211003.131916.345576Z: acpi0: tables DSDT FACP SSDT MCFG TPM2 APIC HEST SSDT
SSDT DRTM HPET
20211003.131916.345718Z: acpi0: wakeup devices PBR4(S4) PBR5(S4) PBR6(S4)
PBR7(S4) PBR8(S4) UOH1(S3) UOH2(S3) UOH3(S3) UOH4(S3) UOH5(S3) UOH6(S3) XHC0(S4)
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Sat, Sep 25, 2021 at 10:25:12AM +0200, Stefan Sperling wrote:
> On Sat, Sep 25, 2021 at 02:03:40AM +, Mikolaj Kucharski wrote:
> > I've added more info, probably mainly for myself. I'm not sure where to
> > go with this information yet.
>
> We need to figure out what makes this code use a group key which
> has been cleared.
>
> Please add printfs for lines of code which modify ic->ic_def_txkey.
> There's one in ieee80211_setkeysdone() which might be particularly
> relevant. It is called from the group key renewal timeout which
> triggers once per hour. Can you reproduce the issue more quickly if
> you change the 3600s timeout in ieee80211_gtk_rekey_timeout() to
> a smaller amount of time, say every 60s?
Hm.. my serial console logging doesn't have timestamps, so I'm not
sure when last `ieee80211_setkeysdone() [ieee80211_proto.c|479]`
happened, before the panic(). Need to spend more time on it.
Full dmesg at the end, from after the crash.
...
MMM: ieee80211_setkeysdone() [ieee80211_proto.c|479] ic_def_txkey modified
MMM: ieee80211_setkeysdone() [ieee80211_proto.c|479] ic_def_txkey modified
MMM: ieee80211_setkeysdone() [ieee80211_proto.c|479] ic_def_txkey modified
MMM: ieee80211_setkeysdone() [ieee80211_proto.c|479] ic_def_txkey modified
MMM: ieee80211_setkeysdone() [ieee80211_proto.c|479] ic_def_txkey modified
MMM: ieee80211_setkeysdone() [ieee80211_proto.c|479] ic_def_txkey modified
MMM: ieee80211_setkeysdone() [ieee80211_proto.c|479] ic_def_txkey modified
MMM: ar5008_tx() [ar5008.c|1521]
MMM: ar5008_tx() [ar5008.c|1524]: key unset for sw crypto: 0
MMM: ieee80211_encrypt() [ieee80211_crypto.c|278]: k_id: 0
MMM: ieee80211_encrypt() [ieee80211_crypto.c|279]: k_flags: 0
MMM: ieee80211_encrypt() [ieee80211_crypto.c|280]: k_len: 0
MMM: ieee80211_encrypt() [ieee80211_crypto.c|281]: k_cipher: 0
MMM: ieee80211_encrypt() [ieee80211_crypto.c|282]: k_key:
0x
panic: ieee80211_encrypt: key unset for sw crypto: id=0 cipher=0 flags=0x0
Stopped at db_enter+0x10: popq%rbp
TIDPIDUID PRFLAGS PFLAGS CPU COMMAND
db_enter() at db_enter+0x10
panic(81ea9632) at panic+0xbf
ieee80211_encrypt(8009c048,fd800a1e6600,80d701c0) at ieee80
211_encrypt+0x473
ar5008_tx(8009c000,fd800a1e6600,80d7,0) at ar5008_tx+0x
1e7
athn_start(8009c048) at athn_start+0x108
ar5008_intr(8009c000) at ar5008_intr+0x216
intr_handler(8000225a6690,8008f780) at intr_handler+0x6e
Xintr_ioapic_level3_untramp() at Xintr_ioapic_level3_untramp+0x193
acpicpu_idle() at acpicpu_idle+0x11f
sched_idle(821a2ff0) at sched_idle+0x27e
end trace frame: 0x0, count: 5
https://www.openbsd.org/ddb.html describes the minimum info required in bug
reports. Insufficient info makes it difficult to find and fix bugs.
ddb{0}>
Kernel runs with changes like this:
diff 1ee6a6fac08dede35833135b1d342d3761412c24 refs/heads/main
blob - 5af62956495d2ce56101817ff6130d5c4b933a60
blob + 5f603acd47d7f2ce52dd9ef7e0761aea0c3d4d37
--- dev/ic/ar5008.c
+++ dev/ic/ar5008.c
@@ -1245,6 +1245,13 @@ ar5008_swba_intr(struct athn_softc *sc)
uint8_t ridx, hwrate;
int error, totlen;
+ /* Stefan Sperling */
+ if (ic->ic_opmode != IEEE80211_M_HOSTAP ||
+ ic->ic_state != IEEE80211_S_RUN) {
+ printf("MMM: %s() [%s|%d] return (ENOTSUP)\n", __func__,
__FILE_NAME__, __LINE__);
+ /* return (ENOTSUP); */
+ }
+
if (ic->ic_tim_mcast_pending &&
mq_empty(>ni_savedq) &&
SIMPLEQ_EMPTY(>txq[ATHN_QID_CAB].head))
blob - e3da39394d224807bec39c777026f26e2a3022ba
blob + 80393859986ed7632e682dfa1c49dd16feaa1a49
--- net80211/ieee80211_ioctl.c
+++ net80211/ieee80211_ioctl.c
@@ -256,6 +256,7 @@ ieee80211_ioctl_setnwkeys(struct ieee80211com *ic,
}
}
+ printf("MMM: %s() [%s|%d] ic_def_txkey modified\n", __func__,
__FILE_NAME__, __LINE__);
ic->ic_def_txkey = nwkey->i_defkid - 1;
ic->ic_flags |= IEEE80211_F_WEPON;
if (ic->ic_flags & IEEE80211_F_RSNON)
blob - 213ef3fc1c96f1aa330597972dab6783ad08399a
blob + e3a949b80a887ff278703809908f83976689b804
--- net80211/ieee80211_node.c
+++ net80211/ieee80211_node.c
@@ -669,6 +669,7 @@ ieee80211_set_ess(struct ieee80211com *ic, struct ieee
sizeof(struct ieee80211_key));
(*ic->ic_set_key)(ic, NULL, k);
}
+ printf("MMM: %s() [%s|%d] ic_def_txkey modified\n", __func__,
__FILE_NAME__, __LINE__);
ic->ic_def_txkey = ess->def_txkey;
ic->ic_flags |= IEEE80211_F_WEPON;
}
@@ -996,6 +997,7 @@ ieee80211_create_ibss(struct ieee80211com* ic, struct
ni->ni_rsncaps |= IEEE80211_RSNCAP_MFPR;
}
+ printf("MMM: %s() [%s|%d] ic_def_txkey modified\n", __func__,
__FILE_NAME__,
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Sat, Sep 25, 2021 at 02:03:40AM +, Mikolaj Kucharski wrote: > I've added more info, probably mainly for myself. I'm not sure where to > go with this information yet. We need to figure out what makes this code use a group key which has been cleared. Please add printfs for lines of code which modify ic->ic_def_txkey. There's one in ieee80211_setkeysdone() which might be particularly relevant. It is called from the group key renewal timeout which triggers once per hour. Can you reproduce the issue more quickly if you change the 3600s timeout in ieee80211_gtk_rekey_timeout() to a smaller amount of time, say every 60s?
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
I've added more info, probably mainly for myself. I'm not sure where to
go with this information yet.
On Sat, Sep 25, 2021 at 01:31:33AM +, Mikolaj Kucharski wrote:
> On Wed, Sep 22, 2021 at 03:00:37PM +, Mikolaj Kucharski wrote:
> > Another one, it happened with below diff applied. Didn't had time yet to
> > dive into this.
>
> I have limited time in recent months, so I'm trying to put anything what
> I have in spare moment. This should be more clear, from my previous
> email.
>
> Entries in dmesg, just before and from the panic()
>
> ddb{0}> dmesg
> OpenBSD 7.0 (GENERIC.MP) #4: Mon Sep 20 08:41:30 UTC 2021
>
> r...@pc1.home.local:/home/mkucharski/openbsd/src/sys/arch/amd64/compile/GENERIC.MP
> ...
> root on sd0a (f4c61a8acb9563fd.a) swap on sd0b dump on sd0b
> MMM: ar5008_tx() [ar5008.c|1521]
> MMM: ar5008_tx() [ar5008.c|1524]: key unset for sw crypto: 0
> MMM: ieee80211_encrypt() [ieee80211_crypto.c|278]: k_id: 0
> MMM: ieee80211_encrypt() [ieee80211_crypto.c|279]: k_flags: 0
> MMM: ieee80211_encrypt() [ieee80211_crypto.c|280]: k_len: 0
> MMM: ieee80211_encrypt() [ieee80211_crypto.c|281]: k_cipher: 0
> MMM: ieee80211_encrypt() [ieee80211_crypto.c|282]: k_key:
> 0x
> panic: ieee80211_encrypt: key unset for sw crypto: id=0 cipher=0 flags=0x0
> Stopped at db_enter+0x10: popq%rbp
> TIDPIDUID PRFLAGS PFLAGS CPU COMMAND
> db_enter() at db_enter+0x10
> panic(81ea79d7) at panic+0xbf
> ieee80211_encrypt(8009c048,fd80c307ce00,80d3e1c0) at
> ieee80211_encrypt+0x473
> ar5008_tx(8009c000,fd80c307ce00,80d3e000,0) at
> ar5008_tx+0x1e7
> athn_start(8009c048) at athn_start+0x108
> ar5008_intr(8009c000) at ar5008_intr+0x216
> intr_handler(8000225a6d80,8008f780) at intr_handler+0x6e
> Xintr_ioapic_level3_untramp() at Xintr_ioapic_level3_untramp+0x193
> acpicpu_idle() at acpicpu_idle+0x11f
> sched_idle(821a7ff0) at sched_idle+0x27e
> end trace frame: 0x0, count: 5
>
>
> Below are dmesg entries and code responsible for those entries.
>
> MMM: ar5008_tx() [ar5008.c|1521]
> MMM: ar5008_tx() [ar5008.c|1524]: key unset for sw crypto: 0
>
> 1514if (wh->i_fc[1] & IEEE80211_FC1_PROTECTED) {
> 1515k = ieee80211_get_txkey(ic, wh, ni);
> 1516if (k->k_cipher == IEEE80211_CIPHER_CCMP) {
> 1517u_int hdrlen = ieee80211_get_hdrlen(wh);
> 1518if (ar5008_ccmp_encap(m, hdrlen, k) !=
> 0)
> 1519return (ENOBUFS);
> 1520} else {
> 1521printf("MMM: %s() [%s|%d]\n", __func__,
> __FILE_NAME__, __LINE__);
> 1522if ((k->k_flags &
> IEEE80211_KEY_SWCRYPTO) == 0)
> 1523printf("MMM: %s() [%s|%d]: key
> unset for sw crypto: %d\n",
> 1524__func__,
> __FILE_NAME__, __LINE__, k->k_id);
> 1525if ((m = ieee80211_encrypt(ic, m, k))
> == NULL)
> 1526return (ENOBUFS);
> 1527k = NULL; /* skip hardware crypto
> further below */
> 1528}
> 1529wh = mtod(m, struct ieee80211_frame *);
> 1530}
>
> MMM: ieee80211_encrypt() [ieee80211_crypto.c|278]: k_id: 0
> MMM: ieee80211_encrypt() [ieee80211_crypto.c|279]: k_flags: 0
> MMM: ieee80211_encrypt() [ieee80211_crypto.c|280]: k_len: 0
> MMM: ieee80211_encrypt() [ieee80211_crypto.c|281]: k_cipher: 0
> MMM: ieee80211_encrypt() [ieee80211_crypto.c|282]: k_key:
> 0x
>
>273struct mbuf *
>274ieee80211_encrypt(struct ieee80211com *ic, struct mbuf *m0,
>275struct ieee80211_key *k)
>276{
>277if ((k->k_flags & IEEE80211_KEY_SWCRYPTO) == 0) {
>278printf("MMM: %s() [%s|%d]: k_id: %d\n",
> __func__, __FILE_NAME__, __LINE__, k->k_id);
>279printf("MMM: %s() [%s|%d]: k_flags: %d\n",
> __func__, __FILE_NAME__, __LINE__, k->k_flags);
>280printf("MMM: %s() [%s|%d]: k_len: %d\n",
> __func__, __FILE_NAME__, __LINE__, k->k_len);
>281printf("MMM: %s() [%s|%d]: k_cipher: %d\n",
> __func__, __FILE_NAME__, __LINE__, k->k_cipher);
>282printf("MMM: %s() [%s|%d]: k_key: 0x",
> __func__, __FILE_NAME__, __LINE__);
>283for (int i = 0; i < sizeof(k->k_key); i++)
>284printf("%02x", k->k_key[i]);
>285printf("\n");
>286}
>
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Wed, Sep 22, 2021 at 03:00:37PM +, Mikolaj Kucharski wrote:
> Another one, it happened with below diff applied. Didn't had time yet to
> dive into this.
I have limited time in recent months, so I'm trying to put anything what
I have in spare moment. This should be more clear, from my previous
email.
Entries in dmesg, just before and from the panic()
ddb{0}> dmesg
OpenBSD 7.0 (GENERIC.MP) #4: Mon Sep 20 08:41:30 UTC 2021
r...@pc1.home.local:/home/mkucharski/openbsd/src/sys/arch/amd64/compile/GENERIC.MP
...
root on sd0a (f4c61a8acb9563fd.a) swap on sd0b dump on sd0b
MMM: ar5008_tx() [ar5008.c|1521]
MMM: ar5008_tx() [ar5008.c|1524]: key unset for sw crypto: 0
MMM: ieee80211_encrypt() [ieee80211_crypto.c|278]: k_id: 0
MMM: ieee80211_encrypt() [ieee80211_crypto.c|279]: k_flags: 0
MMM: ieee80211_encrypt() [ieee80211_crypto.c|280]: k_len: 0
MMM: ieee80211_encrypt() [ieee80211_crypto.c|281]: k_cipher: 0
MMM: ieee80211_encrypt() [ieee80211_crypto.c|282]: k_key:
0x
panic: ieee80211_encrypt: key unset for sw crypto: id=0 cipher=0 flags=0x0
Stopped at db_enter+0x10: popq%rbp
TIDPIDUID PRFLAGS PFLAGS CPU COMMAND
db_enter() at db_enter+0x10
panic(81ea79d7) at panic+0xbf
ieee80211_encrypt(8009c048,fd80c307ce00,80d3e1c0) at
ieee80211_encrypt+0x473
ar5008_tx(8009c000,fd80c307ce00,80d3e000,0) at
ar5008_tx+0x1e7
athn_start(8009c048) at athn_start+0x108
ar5008_intr(8009c000) at ar5008_intr+0x216
intr_handler(8000225a6d80,8008f780) at intr_handler+0x6e
Xintr_ioapic_level3_untramp() at Xintr_ioapic_level3_untramp+0x193
acpicpu_idle() at acpicpu_idle+0x11f
sched_idle(821a7ff0) at sched_idle+0x27e
end trace frame: 0x0, count: 5
Below are dmesg entries and code responsible for those entries.
MMM: ar5008_tx() [ar5008.c|1521]
MMM: ar5008_tx() [ar5008.c|1524]: key unset for sw crypto: 0
1514 if (wh->i_fc[1] & IEEE80211_FC1_PROTECTED) {
1515 k = ieee80211_get_txkey(ic, wh, ni);
1516 if (k->k_cipher == IEEE80211_CIPHER_CCMP) {
1517 u_int hdrlen = ieee80211_get_hdrlen(wh);
1518 if (ar5008_ccmp_encap(m, hdrlen, k) != 0)
1519 return (ENOBUFS);
1520 } else {
1521 printf("MMM: %s() [%s|%d]\n", __func__,
__FILE_NAME__, __LINE__);
1522 if ((k->k_flags & IEEE80211_KEY_SWCRYPTO) == 0)
1523 printf("MMM: %s() [%s|%d]: key unset
for sw crypto: %d\n",
1524 __func__, __FILE_NAME__,
__LINE__, k->k_id);
1525 if ((m = ieee80211_encrypt(ic, m, k)) == NULL)
1526 return (ENOBUFS);
1527 k = NULL; /* skip hardware crypto further below
*/
1528 }
1529 wh = mtod(m, struct ieee80211_frame *);
1530 }
MMM: ieee80211_encrypt() [ieee80211_crypto.c|278]: k_id: 0
MMM: ieee80211_encrypt() [ieee80211_crypto.c|279]: k_flags: 0
MMM: ieee80211_encrypt() [ieee80211_crypto.c|280]: k_len: 0
MMM: ieee80211_encrypt() [ieee80211_crypto.c|281]: k_cipher: 0
MMM: ieee80211_encrypt() [ieee80211_crypto.c|282]: k_key:
0x
273 struct mbuf *
274 ieee80211_encrypt(struct ieee80211com *ic, struct mbuf *m0,
275 struct ieee80211_key *k)
276 {
277 if ((k->k_flags & IEEE80211_KEY_SWCRYPTO) == 0) {
278 printf("MMM: %s() [%s|%d]: k_id: %d\n", __func__,
__FILE_NAME__, __LINE__, k->k_id);
279 printf("MMM: %s() [%s|%d]: k_flags: %d\n", __func__,
__FILE_NAME__, __LINE__, k->k_flags);
280 printf("MMM: %s() [%s|%d]: k_len: %d\n", __func__,
__FILE_NAME__, __LINE__, k->k_len);
281 printf("MMM: %s() [%s|%d]: k_cipher: %d\n", __func__,
__FILE_NAME__, __LINE__, k->k_cipher);
282 printf("MMM: %s() [%s|%d]: k_key: 0x", __func__,
__FILE_NAME__, __LINE__);
283 for (int i = 0; i < sizeof(k->k_key); i++)
284 printf("%02x", k->k_key[i]);
285 printf("\n");
286 }
287
288 if ((k->k_flags & IEEE80211_KEY_SWCRYPTO) == 0)
289 panic("%s: key unset for sw crypto: id=%d cipher=%d
flags=0x%x",
290 __func__, k->k_id, k->k_cipher, k->k_flags);
291
panic: ieee80211_encrypt: key unset for sw crypto: id=0 cipher=0 flags=0x0
Stopped at db_enter+0x10: popq%rbp
TIDPIDUID PRFLAGS PFLAGS CPU COMMAND
db_enter() at db_enter+0x10
panic(81ea79d7) at panic+0xbf
ieee80211_encrypt(8009c048,fd80c307ce00,80d3e1c0)
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
Another one, it happened with below diff applied. Didn't had time yet to
dive into this.
---
commit 94d934f45b45bd87293428425164d8120ec10255 (main)
from: Mikolaj Kucharski
date: Mon Sep 20 08:35:49 2021 UTC
ignore the SWBA interrupt while we're not in RUN state
diff 2cd8545e477139b6c38791b115f0a983e1171705
5a9d942f0a06316203dd6a5c1b2d057187962d57
blob - 5af62956495d2ce56101817ff6130d5c4b933a60
blob + 5f603acd47d7f2ce52dd9ef7e0761aea0c3d4d37
--- dev/ic/ar5008.c
+++ dev/ic/ar5008.c
@@ -1245,6 +1245,13 @@ ar5008_swba_intr(struct athn_softc *sc)
uint8_t ridx, hwrate;
int error, totlen;
+ /* Stefan Sperling */
+ if (ic->ic_opmode != IEEE80211_M_HOSTAP ||
+ ic->ic_state != IEEE80211_S_RUN) {
+ printf("MMM: %s() [%s|%d] return (ENOTSUP)\n", __func__,
__FILE_NAME__, __LINE__);
+ /* return (ENOTSUP); */
+ }
+
if (ic->ic_tim_mcast_pending &&
mq_empty(>ni_savedq) &&
SIMPLEQ_EMPTY(>txq[ATHN_QID_CAB].head))
---
commit d655a89071a6be117fc8d839bb3697696d629e5c
from: Mikolaj Kucharski
date: Mon Sep 20 08:35:49 2021 UTC
custom debugging changes
diff 4016d99f4a6705e785703d1696d76a53d8b5bc88
2cd8545e477139b6c38791b115f0a983e1171705
blob - ff58831e5f15802b7468e8d25332b7510b7ed333
blob + 9c1bfede2f3203b632dcd0cb0e81340fb01de4b2
--- arch/hppa/hppa/mutex.c
+++ arch/hppa/hppa/mutex.c
@@ -74,7 +74,7 @@ mtx_enter_try(struct mutex *mtx)
#ifdef DIAGNOSTIC
if (__predict_false(mtx->mtx_owner == ci))
- panic("mtx %p: locking against myself", mtx);
+ panic("%s: mtx %p: locking against myself", __func__, mtx);
#endif
asm volatile (
@@ -108,7 +108,7 @@ mtx_enter(struct mutex *mtx)
#ifdef DIAGNOSTIC
if (__predict_false(mtx->mtx_owner == ci))
- panic("mtx %p: locking against myself", mtx);
+ panic("%s: mtx %p: locking against myself", __func__, mtx);
#endif
if (mtx->mtx_wantipl != IPL_NONE)
blob - ff04d0699000c7a8975c7d1238368d8f34a4c128
blob + 03eb78368c58af12e0b664d2d1165ac746971453
--- arch/m88k/m88k/mutex.c
+++ arch/m88k/m88k/mutex.c
@@ -104,7 +104,7 @@ mtx_enter_try(struct mutex *mtx)
#ifdef DIAGNOSTIC
if (__predict_false(mtx->mtx_owner == ci))
- panic("mtx %p: locking against myself", mtx);
+ panic("%s: mtx %p: locking against myself", __func__, mtx);
#endif
if (mtx->mtx_wantipl != IPL_NONE)
splx(s);
@@ -126,7 +126,7 @@ mtx_enter(struct mutex *mtx)
#ifdef DIAGNOSTIC
if (__predict_false(mtx->mtx_owner == ci))
- panic("mtx %p: locking against myself", mtx);
+ panic("%s: mtx %p: locking against myself", __func__, mtx);
#endif
if (mtx->mtx_wantipl != IPL_NONE)
blob - 6ace32dbff3f26941eab5836419dc7e600f1b32e
blob + f2111282aa6e3b8db97208f462a7b73613f5481c
--- dev/ic/aic6915.c
+++ dev/ic/aic6915.c
@@ -492,7 +492,7 @@ sf_watchdog(struct ifnet *ifp)
{
struct sf_softc *sc = ifp->if_softc;
- printf("%s: device timeout\n", sc->sc_dev.dv_xname);
+ printf("%s: device timeout [%s()|%s|%d]\n", sc->sc_dev.dv_xname,
__func__, __FILE_NAME__, __LINE__);
ifp->if_oerrors++;
(void) sf_init(ifp);
blob - 6208492c94c2af3d15e158e8329f881565efd232
blob + 09f644585c55d24f495fc3fe35926d68ffc5ff1c
--- dev/ic/an.c
+++ dev/ic/an.c
@@ -1261,7 +1261,7 @@ an_watchdog(struct ifnet *ifp)
if (sc->sc_tx_timer) {
if (--sc->sc_tx_timer == 0) {
- printf("%s: device timeout\n", ifp->if_xname);
+ printf("%s: device timeout [%s()|%s|%d]\n",
ifp->if_xname, __func__, __FILE_NAME__, __LINE__);
ifp->if_oerrors++;
an_init(ifp);
return;
blob - ea1f278ed8f363012fc1922c04adf311b50d38e9
blob + 5af62956495d2ce56101817ff6130d5c4b933a60
--- dev/ic/ar5008.c
+++ dev/ic/ar5008.c
@@ -1511,6 +1511,10 @@ ar5008_tx(struct athn_softc *sc, struct mbuf *m, struc
if (ar5008_ccmp_encap(m, hdrlen, k) != 0)
return (ENOBUFS);
} else {
+ printf("MMM: %s() [%s|%d]\n", __func__, __FILE_NAME__,
__LINE__);
+ if ((k->k_flags & IEEE80211_KEY_SWCRYPTO) == 0)
+ printf("MMM: %s() [%s|%d]: key unset for sw
crypto: %d\n",
+ __func__, __FILE_NAME__, __LINE__,
k->k_id);
if ((m = ieee80211_encrypt(ic, m, k)) == NULL)
return (ENOBUFS);
k = NULL; /* skip hardware crypto further below */
blob - 9a640630ecdd5e55125bae10cbd31665bf7ce9e6
blob + c9411ad18013dd674437b97d25e0dcd68dad2a5c
--- dev/ic/ath.c
+++ dev/ic/ath.c
@@ -931,7 +931,7 @@ ath_watchdog(struct ifnet
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Tue, Apr 27, 2021 at 11:32:49PM +0200, Stefan Sperling wrote:
> On Tue, Apr 27, 2021 at 06:36:32PM +, Mikolaj Kucharski wrote:
> > I got it again, but had official snapshot, so I don't have more info
> > than I had in the past, but I would like to share it anyway..
>
> > ddb{0}> show panic
> > ieee80211_encrypt: key unset for sw crypto: 0
>
> It would be nice to have more information about the bad key.
> Could you run with this?
>
> diff 87962d75d1c1a416b89e927cd4ab8e3327a47509 /usr/src
> blob - 037aca21138df15a4b0b8ec2a96afd8d67c5e3cc
> file + sys/net80211/ieee80211_crypto.c
> --- sys/net80211/ieee80211_crypto.c
> +++ sys/net80211/ieee80211_crypto.c
> @@ -257,8 +257,10 @@ struct mbuf *
> ieee80211_encrypt(struct ieee80211com *ic, struct mbuf *m0,
> struct ieee80211_key *k)
> {
> - if ((k->k_flags & IEEE80211_KEY_SWCRYPTO) == 0)
> - panic("%s: key unset for sw crypto: %d", __func__, k->k_id);
> + if ((k->k_flags & IEEE80211_KEY_SWCRYPTO) == 0) {
> + panic("%s: key unset for sw crypto: id=%d cipher=%d flags=0x%x",
> + __func__, k->k_id, k->k_cipher, k->k_flags);
> + }
>
> switch (k->k_cipher) {
> case IEEE80211_CIPHER_WEP40:
Just got kernel panic, with above change committed while ago, panic says
now:
ieee80211_encrypt: key unset for sw crypto: id=0 cipher=0 flags=0x0
ddb{0}> set $lines = 0
ddb{0}> set $maxwidth = 0
ddb{0}> show panic
*cpu0: ieee80211_encrypt: key unset for sw crypto: id=0 cipher=0 flags=0x0
ddb{0}> trace
db_enter() at db_enter+0x10
panic(81e96e93) at panic+0xbf
ieee80211_encrypt(8009c048,fd80cd8a0300,80d481c0) at
ieee80211_encrypt+0x67
ar5008_tx(8009c000,fd80cd8a0300,80d48000,0) at
ar5008_tx+0x17e
athn_start(8009c048) at athn_start+0x108
ar5008_intr(8009c000) at ar5008_intr+0x216
intr_handler(8000225a6790,80093800) at intr_handler+0x6e
Xintr_ioapic_level3_untramp() at Xintr_ioapic_level3_untramp+0x193
acpicpu_idle() at acpicpu_idle+0x11f
sched_idle(8215fff0) at sched_idle+0x27e
end trace frame: 0x0, count: -10
ddb{0}> machine cpuinfo
* 0: ddb
1: stopped
2: stopped
3: stopped
ddb{0}> show registers
rdi0
rsi 0x14
rbp 0x8000225a64f0
rbx 0xfd800a1c1800
rdx 0xc8000c10
rcx0x202
rax 0x4b
r8 0x101010101010101
r9 0
r100
r11 0xd9bbbe70e36bcefb
r12 0x82160a00cpu_info_full_primary+0x2a00
r13 0x8009c048
r140
r15 0x81e96e93apollo_udma100_tim+0x66ab
rip 0x817a54f0db_enter+0x10
cs 0x8
rflags 0x282
rsp 0x8000225a64f0
ss 0x10
db_enter+0x10: popq%rbp
ddb{0}> show proc
PROC (idle0) pid=288157 stat=onproc
flags process=14000 proc=4200
pri=0, usrpri=50, nice=20
forw=0xb998e34e6030d4d8, list=0x8000fce0,0x8000f7b0
process=0x8000d7a0 user=0x8000225a1000,
vmspace=0x822bda00
estcpu=0, cpticks=15218505, pctcpu=0.0
user=0, sys=0, intr=1
ddb{0}> ps
PID TID PPIDUID S FLAGS WAIT COMMAND
6570 17370 89020 27 30x100090 selectsshd
89020 136355 11734 0 30x82 poll sshd
74596 305331 14627 0 30x100082 nanoslp sleep
46203 387806 83607 32767 30x100082 nanoslp sleep
2603 32551 87780 0 30x100082 nanoslp sleep
85292 244755 16488 0 30x100082 nanoslp sleep
12122 33526 34030 0 30x100083 ttyin ksh
92419 249612 34030 0 30x100083 kqreadcu
11340 131604 34030 0 30x100083 ttyin ksh
34030 436081 1 0 30x100080 kqreadtmux
72008 235496 1 0 30x100083 ttyin getty
48258 180627 1 0 30x100098 poll cron
26545 512225 1847 30x80 selectiperf3
75148 292034 1658 30x80 nanoslp vnstatd
16488 361525 1 0 30x10008b sigsusp sh
87780 314505 1 0 30x10008b sigsusp sh
83607 282895 1 32767 30x10008b sigsusp sh
14627 192947 1 0 30x10008b sigsusp sh
88569 465891 1577 30x90 poll openvpn
94868 301493 1 79 30x100090 kqreadtftpd
46848 250609 1 0 30x100080 kqreadhttpd
52600 114446 1 67 30x100092 kqreadhttpd
468065477 1 67 30x100092 kqreadhttpd
89331
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Tue, May 11, 2021 at 10:28:21AM +0200, Stefan Sperling wrote:
> On Sun, May 09, 2021 at 08:28:14PM +, Mikolaj Kucharski wrote:
> > ..and in case timestamps may give a bit more clue, here is example from
> > one of the accesspoints:
>
> Yes, this is insightful:
>
> > # grep -F ieee80211_encap /var/log/messages
> > 2021-05-09T11:35:31.155Z pce-0041 /bsd: ieee80211_encap: data frame for
> > node c0:ee:fb:33:f0:11 in state 4
>
> At this point the node was in COLLECT state.
>
> This happens if the node deliberately disassociates or if the AP doesn't
> see activity from the node for a while. Which should be a common case for
> phones that walk in and out of range.
>
> > 2021-05-09T11:36:07.957Z pce-0041 /bsd: ieee80211_encap: data frame for
> > node c0:ee:fb:33:f0:11 in state 4
> > 2021-05-09T11:36:07.964Z pce-0041 /bsd: ieee80211_encap: data frame for
> > node c0:ee:fb:33:f0:11 in state 4
> > 2021-05-09T19:14:34.117Z pce-0041 /bsd: ieee80211_encap: data frame for
> > node c0:ee:fb:33:f0:11 in state 4
> > 2021-05-09T19:14:34.567Z pce-0041 /bsd: ieee80211_encap: data frame for
> > node c0:ee:fb:33:f0:11 in state 4
> > 2021-05-09T19:14:37.467Z pce-0041 /bsd: ieee80211_encap: data frame for
> > node c0:ee:fb:33:f0:11 in state 4
> > 2021-05-09T19:14:44.217Z pce-0041 /bsd: ieee80211_encap: data frame for
> > node c0:ee:fb:33:f0:11 in state 4
>
> My guess is that all of these frames were broadcasts which get sent to
> all nodes. It doesn't look like a data stream that targets this particular
> node since the packets are far apart from each other.
>
> > 2021-05-09T19:14:49.267Z pce-0041 /bsd: ieee80211_encap: data frame for
> > node c0:ee:fb:33:f0:11 in state 2
>
> The phone came back, and is in state AUTH.
> Not sure why it stays in this state for a while. Maybe it has decided to
> try a different AP after all and never made it back into ASSOC state this
> time around?
Unlikely, at this location there is only one access point which is
configured on that mobile phone. Tha OnePlus mobile doesn't have
other choice than that pce-0041 with athn(4).
I have machine with unused iwn(4) in that location and I started
recently below tcpdumploop script (don't have tcpdumps during
above logs, as I wrote tcpdumploop after above testing):
---8<---
#!/bin/sh
#
# $OpenBSD$
daemon="/bin/sh /opt/bin/tcpdumploop"
daemon_logger="daemon.info"
. /etc/rc.d/rc.subr
rc_reload=NO
rc_bg=YES
rc_stop() {
local parent=$(pgrep -T "${daemon_rtable}" -xf "${pexp}")
if [ -z "${parent}" ]
then
# daemon not running?
return 1
fi
pkill -T "${daemon_rtable}" -P "${parent}"
kill "${parent}"
}
rc_cmd $1
--->8---
---8<---
#!/bin/sh
set -e
umask 077
if='iwn0'
chan='6'
count='100'
dir='/home/tcpdumps'
ifconfig $if mediaopt monitor
ifconfig $if chan $chan
ifconfig $if up
while :
do
find "$dir" -maxdepth 1 -type f -iname '*.pcap' -mtime +30 -ls -delete
|| :
ts=`date -u '+%Y%m%d-%H%M%S'`
rnd=`openssl rand -hex 8`
pcap="$if-$ts-$rnd.pcap"
echo "saving $count packets on $if interface to $dir/$pcap"
rm -vf "$dir/$pcap"
tcpdump -c $count -n -i $if -y IEEE802_11_RADIO -s 4096 -w "$dir/$pcap"
done
--->8---
Maybe it will be useful in the future? I never used tcpdump(8) with that
iwn(4), so not sure how reliable it works:
pc1# dmesg | grep -e iwn
iwn0 at pci2 dev 0 function 0 "Intel WiFi Link 5100" rev 0x00: msi, MIMO 1T2R,
MoW, address 00:24:d6:92:e9:f0
pc1# ifconfig iwn0
iwn0: flags=8943 mtu 1500
lladdr 00:24:d6:92:e9:f0
index 2 priority 4 llprio 3
groups: wlan
media: IEEE802.11 autoselect monitor
status: active
ieee80211: nwid ""
I also didn't even look at those tcpdumps, so not sure what's inside
them:
pc1# ls -lh /home/tcpdumps/
total 7300448
-rw--- 1 root wheel 589M May 10 04:49
iwn0-20210510-042148-5d168b68375a1877.pcap
-rw--- 1 root wheel 424M May 10 12:08
iwn0-20210510-044948-3755e8e9d53154b6.pcap
-rw--- 1 root wheel 348M May 10 16:54
iwn0-20210510-120844-f15d72c75800b384.pcap
-rw--- 1 root wheel 278M May 10 20:55
iwn0-20210510-165442-71b19d49c5c85f67.pcap
-rw--- 1 root wheel 486M May 11 08:18
iwn0-20210510-205507-8d0cac31a70203be.pcap
-rw--- 1 root wheel 255M May 11 18:05
iwn0-20210511-081820-f54c1262501bc25b.pcap
-rw--- 1 root wheel 546M May 11 18:24
iwn0-20210511-180553-5a6b939813426388.pcap
-rw--- 1 root wheel 639M May 11 19:37
iwn0-20210511-182414-5232129b4cc89335.pcap
> > 2021-05-09T19:14:50.317Z pce-0041 /bsd: ieee80211_encap: data frame for
> > node c0:ee:fb:33:f0:11 in state 2
> > 2021-05-09T19:14:51.317Z pce-0041 /bsd: ieee80211_encap: data frame for
> > node c0:ee:fb:33:f0:11 in state 2
> > 2021-05-09T19:14:53.317Z pce-0041 /bsd: ieee80211_encap: data frame for
> > node c0:ee:fb:33:f0:11 in state 2
> > 2021-05-09T19:14:57.318Z pce-0041 /bsd:
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
..and in case timestamps may give a bit more clue, here is example from one of the accesspoints: # grep -F ieee80211_encap /var/log/messages 2021-05-09T11:35:31.155Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T11:36:07.957Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T11:36:07.964Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:14:34.117Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:14:34.567Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:14:37.467Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:14:44.217Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:14:49.267Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 2 2021-05-09T19:14:50.317Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 2 2021-05-09T19:14:51.317Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 2 2021-05-09T19:14:53.317Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 2 2021-05-09T19:14:57.318Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 2 2021-05-09T19:16:06.170Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:06.620Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:06.720Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:07.423Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:07.425Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:08.620Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:08.920Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:08.922Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:10.570Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:11.870Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:11.872Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:15.473Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:15.770Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:16.020Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:16.620Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:17.670Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:17.770Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:17.772Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:19.870Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:21.820Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:22.320Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:24.520Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:29.521Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:31.871Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:33.221Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:16:50.671Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:18:14.074Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:18:14.674Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:18:16.424Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:18:19.874Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:18:26.225Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:18:26.774Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:18:40.575Z pce-0041 /bsd: ieee80211_encap: data frame for node c0:ee:fb:33:f0:11 in state 4 2021-05-09T19:19:08.226Z pce-0041 /bsd:
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Sat, May 08, 2021 at 10:06:08AM +0200, Stefan Sperling wrote:
>
> Fixed patch, with the condition ni != ic->ic_bss added:
>
> diff b412d6f4250f42e50e0333dbcedab9189b4b19e2 /usr/src
> blob - 58f654273f7ea0cc3c04e0a60d5e5e6a33296dc0
> file + sys/net80211/ieee80211_output.c
> --- sys/net80211/ieee80211_output.c
> +++ sys/net80211/ieee80211_output.c
> @@ -556,6 +556,16 @@ ieee80211_encap(struct ifnet *ifp, struct mbuf *m, str
> goto bad;
> }
>
> +#ifndef IEEE80211_STA_ONLY
> + if (ic->ic_opmode == IEEE80211_M_HOSTAP && ni != ic->ic_bss &&
> + ni->ni_state != IEEE80211_STA_ASSOC) {
> + printf("%s: data frame for node %s in state %d\n",
> + __func__, ether_sprintf(ni->ni_macaddr), ni->ni_state);
> + ic->ic_stats.is_tx_nonode++;
> + goto bad;
> + }
> +#endif
> +
> if ((ic->ic_flags & IEEE80211_F_RSNON) &&
> !ni->ni_port_valid &&
> eh.ether_type != htons(ETHERTYPE_PAE)) {
After about 1 day of uptime from both machines, ieee80211_encap()
messages are visible, mostly with Android phones (maybe, because
those are the most common Wi-Fi clients in both households, as in
have longest uptime within 24 hrs, longest connected to accesspoint).
No kernel panics occurred.
== pce-0041 ==
OpenBSD 6.9-current (GENERIC.MP) #13: Sat May 8 13:59:22 UTC 2021
r...@pc1.home.local:/home/mkucharski/openbsd/src/sys/arch/amd64/compile/GENERIC.MP
real mem = 4259872768 (4062MB)
avail mem = 4115308544 (3924MB)
random: good seed from bootblocks
mpath0 at root
scsibus0 at mpath0: 256 targets
mainbus0 at root
bios0 at mainbus0: SMBIOS rev. 2.8 @ 0xcfe8b020 (13 entries)
bios0: vendor coreboot version "v4.12.0.3" date 07/30/2020
bios0: PC Engines apu3
acpi0 at bios0: ACPI 6.0
acpi0: sleep states S0 S1 S4 S5
acpi0: tables DSDT FACP SSDT MCFG TPM2 APIC HEST SSDT SSDT DRTM HPET
acpi0: wakeup devices PBR4(S4) PBR5(S4) PBR6(S4) PBR7(S4) PBR8(S4) UOH1(S3)
UOH2(S3) UOH3(S3) UOH4(S3) UOH5(S3) UOH6(S3) XHC0(S4)
acpitimer0 at acpi0: 3579545 Hz, 32 bits
acpimcfg0 at acpi0
acpimcfg0: addr 0xf800, bus 0-64
acpimadt0 at acpi0 addr 0xfee0: PC-AT compat
cpu0 at mainbus0: apid 0 (boot processor)
cpu0: AMD GX-412TC SOC, 998.27 MHz, 16-30-01
cpu0:
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,MMX,FXSR,SSE,SSE2,HTT,SSE3,PCLMUL,MWAIT,SSSE3,CX16,SSE4.1,SSE4.2,MOVBE,POPCNT,AES,XSAVE,AVX,F16C,NXE,MMXX,FFXSR,PAGE1GB,RDTSCP,LONG,LAHF,CMPLEG,SVM,EAPICSP,AMCR8,ABM,SSE4A,MASSE,3DNOWP,OSVW,IBS,SKINIT,TOPEXT,DBKP,PERFTSC,PCTRL3,ITSC,BMI1,XSAVEOPT
cpu0: 32KB 64b/line 2-way I-cache, 32KB 64b/line 8-way D-cache, 2MB 64b/line
16-way L2 cache
cpu0: ITLB 32 4KB entries fully associative, 8 4MB entries fully associative
cpu0: DTLB 40 4KB entries fully associative, 8 4MB entries fully associative
cpu0: smt 0, core 0, package 0
mtrr: Pentium Pro MTRR support, 8 var ranges, 88 fixed ranges
cpu0: apic clock running at 99MHz
cpu0: mwait min=64, max=64, IBE
cpu1 at mainbus0: apid 1 (application processor)
cpu1: AMD GX-412TC SOC, 998.14 MHz, 16-30-01
cpu1:
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,MMX,FXSR,SSE,SSE2,HTT,SSE3,PCLMUL,MWAIT,SSSE3,CX16,SSE4.1,SSE4.2,MOVBE,POPCNT,AES,XSAVE,AVX,F16C,NXE,MMXX,FFXSR,PAGE1GB,RDTSCP,LONG,LAHF,CMPLEG,SVM,EAPICSP,AMCR8,ABM,SSE4A,MASSE,3DNOWP,OSVW,IBS,SKINIT,TOPEXT,DBKP,PERFTSC,PCTRL3,ITSC,BMI1,XSAVEOPT
cpu1: 32KB 64b/line 2-way I-cache, 32KB 64b/line 8-way D-cache, 2MB 64b/line
16-way L2 cache
cpu1: ITLB 32 4KB entries fully associative, 8 4MB entries fully associative
cpu1: DTLB 40 4KB entries fully associative, 8 4MB entries fully associative
cpu1: smt 0, core 1, package 0
cpu2 at mainbus0: apid 2 (application processor)
cpu2: AMD GX-412TC SOC, 998.18 MHz, 16-30-01
cpu2:
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,MMX,FXSR,SSE,SSE2,HTT,SSE3,PCLMUL,MWAIT,SSSE3,CX16,SSE4.1,SSE4.2,MOVBE,POPCNT,AES,XSAVE,AVX,F16C,NXE,MMXX,FFXSR,PAGE1GB,RDTSCP,LONG,LAHF,CMPLEG,SVM,EAPICSP,AMCR8,ABM,SSE4A,MASSE,3DNOWP,OSVW,IBS,SKINIT,TOPEXT,DBKP,PERFTSC,PCTRL3,ITSC,BMI1,XSAVEOPT
cpu2: 32KB 64b/line 2-way I-cache, 32KB 64b/line 8-way D-cache, 2MB 64b/line
16-way L2 cache
cpu2: ITLB 32 4KB entries fully associative, 8 4MB entries fully associative
cpu2: DTLB 40 4KB entries fully associative, 8 4MB entries fully associative
cpu2: smt 0, core 2, package 0
cpu3 at mainbus0: apid 3 (application processor)
cpu3: AMD GX-412TC SOC, 998.14 MHz, 16-30-01
cpu3:
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,MMX,FXSR,SSE,SSE2,HTT,SSE3,PCLMUL,MWAIT,SSSE3,CX16,SSE4.1,SSE4.2,MOVBE,POPCNT,AES,XSAVE,AVX,F16C,NXE,MMXX,FFXSR,PAGE1GB,RDTSCP,LONG,LAHF,CMPLEG,SVM,EAPICSP,AMCR8,ABM,SSE4A,MASSE,3DNOWP,OSVW,IBS,SKINIT,TOPEXT,DBKP,PERFTSC,PCTRL3,ITSC,BMI1,XSAVEOPT
cpu3: 32KB 64b/line 2-way I-cache, 32KB 64b/line 8-way D-cache, 2MB 64b/line
16-way L2 cache
cpu3: ITLB 32 4KB entries fully associative, 8 4MB entries fully
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
Hi Mikolaj, Stefan,
Am 08.05.21 um 16:16 schrieb Mikolaj Kucharski:
> On Sat, May 08, 2021 at 10:06:08AM +0200, Stefan Sperling wrote:
>> On Fri, May 07, 2021 at 10:27:36PM +, Mikolaj Kucharski wrote:
>>> Yes, I see ieee80211_encap: data frame for node... messages in
>>> dmesg. Two dmesgs, from two PC Engines machines, in two different
>>> locations, 150+km apart, below.
>>>
>>> Uptime of 12 minutes as hostap from pce-0041:
>>
>>> athn0: AR9280 rev 2 (2T2R), ROM rev 22, address 04:f0:21:34:e4:23
>>
>>> ieee80211_encap: data frame for node 04:f0:21:34:e4:23 in state 0
>>
>> Ooops, sorry I made a mistake. This is the MAC address of the AP itself.
>> The new check I am adding here should obviously exclude the AP itself.
>> Otherwise your AP won't work very well because it blocks its own broadcasts.
>>
>> Fixed patch, with the condition ni != ic->ic_bss added:
>>
>> diff b412d6f4250f42e50e0333dbcedab9189b4b19e2 /usr/src
>> blob - 58f654273f7ea0cc3c04e0a60d5e5e6a33296dc0
>> file + sys/net80211/ieee80211_output.c
>> --- sys/net80211/ieee80211_output.c
>> +++ sys/net80211/ieee80211_output.c
>> @@ -556,6 +556,16 @@ ieee80211_encap(struct ifnet *ifp, struct mbuf *m, str
>> goto bad;
>> }
>>
>> +#ifndef IEEE80211_STA_ONLY
>> +if (ic->ic_opmode == IEEE80211_M_HOSTAP && ni != ic->ic_bss &&
>> +ni->ni_state != IEEE80211_STA_ASSOC) {
>> +printf("%s: data frame for node %s in state %d\n",
>> +__func__, ether_sprintf(ni->ni_macaddr), ni->ni_state);
>> +ic->ic_stats.is_tx_nonode++;
>> +goto bad;
>> +}
>> +#endif
>> +
>> if ((ic->ic_flags & IEEE80211_F_RSNON) &&
>> !ni->ni_port_valid &&
>> eh.ether_type != htons(ETHERTYPE_PAE)) {
>
> So far nothing, 10 min of uptime for both machines:
>
> pce-0035# dmesg | grep -cF ieee80211_encap
> 0
>
> # dmesg | grep -cF ieee80211_encap
> 0
>
Sorry if this should be obvious - How can I test this myself?
Thanks
Stephen
OpenPGP_signature
Description: OpenPGP digital signature
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Sat, May 08, 2021 at 10:06:08AM +0200, Stefan Sperling wrote:
> On Fri, May 07, 2021 at 10:27:36PM +, Mikolaj Kucharski wrote:
> > Yes, I see ieee80211_encap: data frame for node... messages in
> > dmesg. Two dmesgs, from two PC Engines machines, in two different
> > locations, 150+km apart, below.
> >
> > Uptime of 12 minutes as hostap from pce-0041:
>
> > athn0: AR9280 rev 2 (2T2R), ROM rev 22, address 04:f0:21:34:e4:23
>
> > ieee80211_encap: data frame for node 04:f0:21:34:e4:23 in state 0
>
> Ooops, sorry I made a mistake. This is the MAC address of the AP itself.
> The new check I am adding here should obviously exclude the AP itself.
> Otherwise your AP won't work very well because it blocks its own broadcasts.
>
> Fixed patch, with the condition ni != ic->ic_bss added:
>
> diff b412d6f4250f42e50e0333dbcedab9189b4b19e2 /usr/src
> blob - 58f654273f7ea0cc3c04e0a60d5e5e6a33296dc0
> file + sys/net80211/ieee80211_output.c
> --- sys/net80211/ieee80211_output.c
> +++ sys/net80211/ieee80211_output.c
> @@ -556,6 +556,16 @@ ieee80211_encap(struct ifnet *ifp, struct mbuf *m, str
> goto bad;
> }
>
> +#ifndef IEEE80211_STA_ONLY
> + if (ic->ic_opmode == IEEE80211_M_HOSTAP && ni != ic->ic_bss &&
> + ni->ni_state != IEEE80211_STA_ASSOC) {
> + printf("%s: data frame for node %s in state %d\n",
> + __func__, ether_sprintf(ni->ni_macaddr), ni->ni_state);
> + ic->ic_stats.is_tx_nonode++;
> + goto bad;
> + }
> +#endif
> +
> if ((ic->ic_flags & IEEE80211_F_RSNON) &&
> !ni->ni_port_valid &&
> eh.ether_type != htons(ETHERTYPE_PAE)) {
So far nothing, 10 min of uptime for both machines:
pce-0035# dmesg | grep -cF ieee80211_encap
0
# dmesg | grep -cF ieee80211_encap
0
--
Regards,
Mikolaj
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Sat, May 08, 2021 at 09:51:06AM +0200, Stefan Sperling wrote: > > > > Do you think above could be committed to HEAD? > > Yes, I will commit it. > Cool, thanks! > > Wrong place, wong time.. but could `got rebase` return dedicated > > exit code for below situation? > > > > $ got rebase main > > got: refs/heads/main is already based on refs/heads/key-unset-printf-trigger > > > > At present it's exit code 1, but if that would be lets say 2, I could > > improve my automation script to rebase stack of my diffs and rebuild > > my custom kernel in more efficient manner. Probably without human > > intervention. > > How about returning exit code 0 in this case? There's nothing to be done > so the command could "trivially" succeed. That's even better! -- Regards, Mikolaj
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Fri, May 07, 2021 at 10:27:36PM +, Mikolaj Kucharski wrote:
> Yes, I see ieee80211_encap: data frame for node... messages in
> dmesg. Two dmesgs, from two PC Engines machines, in two different
> locations, 150+km apart, below.
>
> Uptime of 12 minutes as hostap from pce-0041:
> athn0: AR9280 rev 2 (2T2R), ROM rev 22, address 04:f0:21:34:e4:23
> ieee80211_encap: data frame for node 04:f0:21:34:e4:23 in state 0
Ooops, sorry I made a mistake. This is the MAC address of the AP itself.
The new check I am adding here should obviously exclude the AP itself.
Otherwise your AP won't work very well because it blocks its own broadcasts.
Fixed patch, with the condition ni != ic->ic_bss added:
diff b412d6f4250f42e50e0333dbcedab9189b4b19e2 /usr/src
blob - 58f654273f7ea0cc3c04e0a60d5e5e6a33296dc0
file + sys/net80211/ieee80211_output.c
--- sys/net80211/ieee80211_output.c
+++ sys/net80211/ieee80211_output.c
@@ -556,6 +556,16 @@ ieee80211_encap(struct ifnet *ifp, struct mbuf *m, str
goto bad;
}
+#ifndef IEEE80211_STA_ONLY
+ if (ic->ic_opmode == IEEE80211_M_HOSTAP && ni != ic->ic_bss &&
+ ni->ni_state != IEEE80211_STA_ASSOC) {
+ printf("%s: data frame for node %s in state %d\n",
+ __func__, ether_sprintf(ni->ni_macaddr), ni->ni_state);
+ ic->ic_stats.is_tx_nonode++;
+ goto bad;
+ }
+#endif
+
if ((ic->ic_flags & IEEE80211_F_RSNON) &&
!ni->ni_port_valid &&
eh.ether_type != htons(ETHERTYPE_PAE)) {
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Fri, May 07, 2021 at 10:02:56PM +, Mikolaj Kucharski wrote:
> On Tue, Apr 27, 2021 at 11:32:49PM +0200, Stefan Sperling wrote:
> > On Tue, Apr 27, 2021 at 06:36:32PM +, Mikolaj Kucharski wrote:
> > > I got it again, but had official snapshot, so I don't have more info
> > > than I had in the past, but I would like to share it anyway..
> >
> > > ddb{0}> show panic
> > > ieee80211_encrypt: key unset for sw crypto: 0
> >
> > It would be nice to have more information about the bad key.
> > Could you run with this?
> >
> > diff 87962d75d1c1a416b89e927cd4ab8e3327a47509 /usr/src
> > blob - 037aca21138df15a4b0b8ec2a96afd8d67c5e3cc
> > file + sys/net80211/ieee80211_crypto.c
> > --- sys/net80211/ieee80211_crypto.c
> > +++ sys/net80211/ieee80211_crypto.c
> > @@ -257,8 +257,10 @@ struct mbuf *
> > ieee80211_encrypt(struct ieee80211com *ic, struct mbuf *m0,
> > struct ieee80211_key *k)
> > {
> > - if ((k->k_flags & IEEE80211_KEY_SWCRYPTO) == 0)
> > - panic("%s: key unset for sw crypto: %d", __func__, k->k_id);
> > + if ((k->k_flags & IEEE80211_KEY_SWCRYPTO) == 0) {
> > + panic("%s: key unset for sw crypto: id=%d cipher=%d flags=0x%x",
> > + __func__, k->k_id, k->k_cipher, k->k_flags);
> > + }
> >
> > switch (k->k_cipher) {
> > case IEEE80211_CIPHER_WEP40:
>
> Finally managed to `got rebase` all my testing diffs with above
> included and build new kernel. Not deployed yet. Panic is very rare,
> looking at my logs it's between once per quarter and even once per
> half of a year. I'm not always in a position to quickly rebase my
> testing diffs and sometimes I just deploy official snapshot, because
> sysupgrade makes it so super easy.
>
> Do you think above could be committed to HEAD?
Yes, I will commit it.
> Wrong place, wong time.. but could `got rebase` return dedicated
> exit code for below situation?
>
> $ got rebase main
> got: refs/heads/main is already based on refs/heads/key-unset-printf-trigger
>
> At present it's exit code 1, but if that would be lets say 2, I could
> improve my automation script to rebase stack of my diffs and rebuild
> my custom kernel in more efficient manner. Probably without human
> intervention.
How about returning exit code 0 in this case? There's nothing to be done
so the command could "trivially" succeed.
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Wed, Apr 28, 2021 at 12:52:36AM +0200, Stefan Sperling wrote:
>
> Here is another shot in the dark.
> The patch below ensures that we don't attempt to send data frames
> to nodes that aren't in associated state anymore. The node's crypto
> keys would already have been cleared which would explain the panic.
>
> Do you ever see this new printf trigger?
>
> diff 87962d75d1c1a416b89e927cd4ab8e3327a47509 /usr/src
> blob - 58f654273f7ea0cc3c04e0a60d5e5e6a33296dc0
> file + sys/net80211/ieee80211_output.c
> --- sys/net80211/ieee80211_output.c
> +++ sys/net80211/ieee80211_output.c
> @@ -556,6 +556,16 @@ ieee80211_encap(struct ifnet *ifp, struct mbuf *m, str
> goto bad;
> }
>
> +#ifndef IEEE80211_STA_ONLY
> + if (ic->ic_opmode == IEEE80211_M_HOSTAP &&
> + ni->ni_state != IEEE80211_STA_ASSOC) {
> + printf("%s: data frame for node %s in state %d\n",
> + __func__, ether_sprintf(ni->ni_macaddr), ni->ni_state);
> + ic->ic_stats.is_tx_nonode++;
> + goto bad;
> + }
> +#endif
> +
> if ((ic->ic_flags & IEEE80211_F_RSNON) &&
> !ni->ni_port_valid &&
> eh.ether_type != htons(ETHERTYPE_PAE)) {
Yes, I see ieee80211_encap: data frame for node... messages in
dmesg. Two dmesgs, from two PC Engines machines, in two different
locations, 150+km apart, below.
Uptime of 12 minutes as hostap from pce-0041:
OpenBSD 6.9-current (GENERIC.MP) #11: Fri May 7 21:56:51 UTC 2021
r...@pc1.home.local:/home/mkucharski/openbsd/src/sys/arch/amd64/compile/GENERIC.MP
real mem = 4259872768 (4062MB)
avail mem = 4115304448 (3924MB)
random: good seed from bootblocks
mpath0 at root
scsibus0 at mpath0: 256 targets
mainbus0 at root
bios0 at mainbus0: SMBIOS rev. 2.8 @ 0xcfe8b020 (13 entries)
bios0: vendor coreboot version "v4.12.0.3" date 07/30/2020
bios0: PC Engines apu3
acpi0 at bios0: ACPI 6.0
acpi0: sleep states S0 S1 S4 S5
acpi0: tables DSDT FACP SSDT MCFG TPM2 APIC HEST SSDT SSDT DRTM HPET
acpi0: wakeup devices PBR4(S4) PBR5(S4) PBR6(S4) PBR7(S4) PBR8(S4) UOH1(S3)
UOH2(S3) UOH3(S3) UOH4(S3) UOH5(S3) UOH6(S3) XHC0(S4)
acpitimer0 at acpi0: 3579545 Hz, 32 bits
acpimcfg0 at acpi0
acpimcfg0: addr 0xf800, bus 0-64
acpimadt0 at acpi0 addr 0xfee0: PC-AT compat
cpu0 at mainbus0: apid 0 (boot processor)
cpu0: AMD GX-412TC SOC, 998.26 MHz, 16-30-01
cpu0:
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,MMX,FXSR,SSE,SSE2,HTT,SSE3,PCLMUL,MWAIT,SSSE3,CX16,SSE4.1,SSE4.2,MOVBE,POPCNT,AES,XSAVE,AVX,F16C,NXE,MMXX,FFXSR,PAGE1GB,RDTSCP,LONG,LAHF,CMPLEG,SVM,EAPICSP,AMCR8,ABM,SSE4A,MASSE,3DNOWP,OSVW,IBS,SKINIT,TOPEXT,DBKP,PERFTSC,PCTRL3,ITSC,BMI1,XSAVEOPT
cpu0: 32KB 64b/line 2-way I-cache, 32KB 64b/line 8-way D-cache, 2MB 64b/line
16-way L2 cache
cpu0: ITLB 32 4KB entries fully associative, 8 4MB entries fully associative
cpu0: DTLB 40 4KB entries fully associative, 8 4MB entries fully associative
cpu0: smt 0, core 0, package 0
mtrr: Pentium Pro MTRR support, 8 var ranges, 88 fixed ranges
cpu0: apic clock running at 99MHz
cpu0: mwait min=64, max=64, IBE
cpu1 at mainbus0: apid 1 (application processor)
cpu1: AMD GX-412TC SOC, 998.14 MHz, 16-30-01
cpu1:
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,MMX,FXSR,SSE,SSE2,HTT,SSE3,PCLMUL,MWAIT,SSSE3,CX16,SSE4.1,SSE4.2,MOVBE,POPCNT,AES,XSAVE,AVX,F16C,NXE,MMXX,FFXSR,PAGE1GB,RDTSCP,LONG,LAHF,CMPLEG,SVM,EAPICSP,AMCR8,ABM,SSE4A,MASSE,3DNOWP,OSVW,IBS,SKINIT,TOPEXT,DBKP,PERFTSC,PCTRL3,ITSC,BMI1,XSAVEOPT
cpu1: 32KB 64b/line 2-way I-cache, 32KB 64b/line 8-way D-cache, 2MB 64b/line
16-way L2 cache
cpu1: ITLB 32 4KB entries fully associative, 8 4MB entries fully associative
cpu1: DTLB 40 4KB entries fully associative, 8 4MB entries fully associative
cpu1: smt 0, core 1, package 0
cpu2 at mainbus0: apid 2 (application processor)
cpu2: AMD GX-412TC SOC, 998.38 MHz, 16-30-01
cpu2:
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,MMX,FXSR,SSE,SSE2,HTT,SSE3,PCLMUL,MWAIT,SSSE3,CX16,SSE4.1,SSE4.2,MOVBE,POPCNT,AES,XSAVE,AVX,F16C,NXE,MMXX,FFXSR,PAGE1GB,RDTSCP,LONG,LAHF,CMPLEG,SVM,EAPICSP,AMCR8,ABM,SSE4A,MASSE,3DNOWP,OSVW,IBS,SKINIT,TOPEXT,DBKP,PERFTSC,PCTRL3,ITSC,BMI1,XSAVEOPT
cpu2: 32KB 64b/line 2-way I-cache, 32KB 64b/line 8-way D-cache, 2MB 64b/line
16-way L2 cache
cpu2: ITLB 32 4KB entries fully associative, 8 4MB entries fully associative
cpu2: DTLB 40 4KB entries fully associative, 8 4MB entries fully associative
cpu2: smt 0, core 2, package 0
cpu3 at mainbus0: apid 3 (application processor)
cpu3: AMD GX-412TC SOC, 998.13 MHz, 16-30-01
cpu3:
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,MMX,FXSR,SSE,SSE2,HTT,SSE3,PCLMUL,MWAIT,SSSE3,CX16,SSE4.1,SSE4.2,MOVBE,POPCNT,AES,XSAVE,AVX,F16C,NXE,MMXX,FFXSR,PAGE1GB,RDTSCP,LONG,LAHF,CMPLEG,SVM,EAPICSP,AMCR8,ABM,SSE4A,MASSE,3DNOWP,OSVW,IBS,SKINIT,TOPEXT,DBKP,PERFTSC,PCTRL3,ITSC,BMI1,XSAVEOPT
cpu3: 32KB 64b/line 2-way I-cache, 32KB 64b/line
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Wed, Apr 28, 2021 at 12:52:36AM +0200, Stefan Sperling wrote:
> On Tue, Apr 27, 2021 at 11:32:49PM +0200, Stefan Sperling wrote:
> > On Tue, Apr 27, 2021 at 06:36:32PM +, Mikolaj Kucharski wrote:
> > > I got it again, but had official snapshot, so I don't have more info
> > > than I had in the past, but I would like to share it anyway..
> >
> > > ddb{0}> show panic
> > > ieee80211_encrypt: key unset for sw crypto: 0
> >
> > It would be nice to have more information about the bad key.
> > Could you run with this?
>
> Here is another shot in the dark.
> The patch below ensures that we don't attempt to send data frames
> to nodes that aren't in associated state anymore. The node's crypto
> keys would already have been cleared which would explain the panic.
>
> Do you ever see this new printf trigger?
>
> diff 87962d75d1c1a416b89e927cd4ab8e3327a47509 /usr/src
> blob - 58f654273f7ea0cc3c04e0a60d5e5e6a33296dc0
> file + sys/net80211/ieee80211_output.c
> --- sys/net80211/ieee80211_output.c
> +++ sys/net80211/ieee80211_output.c
> @@ -556,6 +556,16 @@ ieee80211_encap(struct ifnet *ifp, struct mbuf *m, str
> goto bad;
> }
>
> +#ifndef IEEE80211_STA_ONLY
> + if (ic->ic_opmode == IEEE80211_M_HOSTAP &&
> + ni->ni_state != IEEE80211_STA_ASSOC) {
> + printf("%s: data frame for node %s in state %d\n",
> + __func__, ether_sprintf(ni->ni_macaddr), ni->ni_state);
> + ic->ic_stats.is_tx_nonode++;
> + goto bad;
> + }
> +#endif
> +
> if ((ic->ic_flags & IEEE80211_F_RSNON) &&
> !ni->ni_port_valid &&
> eh.ether_type != htons(ETHERTYPE_PAE)) {
My custom kernel just finished building with above. Not yet deployed.
--
Regards,
Mikolaj
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Tue, Apr 27, 2021 at 11:32:49PM +0200, Stefan Sperling wrote:
> On Tue, Apr 27, 2021 at 06:36:32PM +, Mikolaj Kucharski wrote:
> > I got it again, but had official snapshot, so I don't have more info
> > than I had in the past, but I would like to share it anyway..
>
> > ddb{0}> show panic
> > ieee80211_encrypt: key unset for sw crypto: 0
>
> It would be nice to have more information about the bad key.
> Could you run with this?
>
> diff 87962d75d1c1a416b89e927cd4ab8e3327a47509 /usr/src
> blob - 037aca21138df15a4b0b8ec2a96afd8d67c5e3cc
> file + sys/net80211/ieee80211_crypto.c
> --- sys/net80211/ieee80211_crypto.c
> +++ sys/net80211/ieee80211_crypto.c
> @@ -257,8 +257,10 @@ struct mbuf *
> ieee80211_encrypt(struct ieee80211com *ic, struct mbuf *m0,
> struct ieee80211_key *k)
> {
> - if ((k->k_flags & IEEE80211_KEY_SWCRYPTO) == 0)
> - panic("%s: key unset for sw crypto: %d", __func__, k->k_id);
> + if ((k->k_flags & IEEE80211_KEY_SWCRYPTO) == 0) {
> + panic("%s: key unset for sw crypto: id=%d cipher=%d flags=0x%x",
> + __func__, k->k_id, k->k_cipher, k->k_flags);
> + }
>
> switch (k->k_cipher) {
> case IEEE80211_CIPHER_WEP40:
Finally managed to `got rebase` all my testing diffs with above
included and build new kernel. Not deployed yet. Panic is very rare,
looking at my logs it's between once per quarter and even once per
half of a year. I'm not always in a position to quickly rebase my
testing diffs and sometimes I just deploy official snapshot, because
sysupgrade makes it so super easy.
Do you think above could be committed to HEAD?
Wrong place, wong time.. but could `got rebase` return dedicated
exit code for below situation?
$ got rebase main
got: refs/heads/main is already based on refs/heads/key-unset-printf-trigger
At present it's exit code 1, but if that would be lets say 2, I could
improve my automation script to rebase stack of my diffs and rebuild
my custom kernel in more efficient manner. Probably without human
intervention.
--
Regards,
Mikolaj
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
Hi Stefan, Mikolaj, all,
I'm glad this is getting renewed attention.
I have been unable to reliably reproduce this, but it still happens to
me from time to time.
(I am still running stable 6.8, just fyi.)
If there's anything else I can do in support, please let me know.
Stephen
Am 28.04.21 um 00:52 schrieb Stefan Sperling:
> On Tue, Apr 27, 2021 at 11:32:49PM +0200, Stefan Sperling wrote:
>> On Tue, Apr 27, 2021 at 06:36:32PM +, Mikolaj Kucharski wrote:
>>> I got it again, but had official snapshot, so I don't have more info
>>> than I had in the past, but I would like to share it anyway..
>>
>>> ddb{0}> show panic
>>> ieee80211_encrypt: key unset for sw crypto: 0
>>
>> It would be nice to have more information about the bad key.
>> Could you run with this?
>
> Here is another shot in the dark.
> The patch below ensures that we don't attempt to send data frames
> to nodes that aren't in associated state anymore. The node's crypto
> keys would already have been cleared which would explain the panic.
>
> Do you ever see this new printf trigger?
>
> diff 87962d75d1c1a416b89e927cd4ab8e3327a47509 /usr/src
> blob - 58f654273f7ea0cc3c04e0a60d5e5e6a33296dc0
> file + sys/net80211/ieee80211_output.c
> --- sys/net80211/ieee80211_output.c
> +++ sys/net80211/ieee80211_output.c
> @@ -556,6 +556,16 @@ ieee80211_encap(struct ifnet *ifp, struct mbuf *m,
str
> goto bad;
> }
>
> +#ifndef IEEE80211_STA_ONLY
> + if (ic->ic_opmode == IEEE80211_M_HOSTAP &&
> + ni->ni_state != IEEE80211_STA_ASSOC) {
> + printf("%s: data frame for node %s in state %d\n",
> + __func__, ether_sprintf(ni->ni_macaddr), ni->ni_state);
> + ic->ic_stats.is_tx_nonode++;
> + goto bad;
> + }
> +#endif
> +
> if ((ic->ic_flags & IEEE80211_F_RSNON) &&
> !ni->ni_port_valid &&
> eh.ether_type != htons(ETHERTYPE_PAE)) {
>
OpenPGP_signature
Description: OpenPGP digital signature
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Tue, Apr 27, 2021 at 11:32:49PM +0200, Stefan Sperling wrote:
> On Tue, Apr 27, 2021 at 06:36:32PM +, Mikolaj Kucharski wrote:
> > I got it again, but had official snapshot, so I don't have more info
> > than I had in the past, but I would like to share it anyway..
>
> > ddb{0}> show panic
> > ieee80211_encrypt: key unset for sw crypto: 0
>
> It would be nice to have more information about the bad key.
> Could you run with this?
Here is another shot in the dark.
The patch below ensures that we don't attempt to send data frames
to nodes that aren't in associated state anymore. The node's crypto
keys would already have been cleared which would explain the panic.
Do you ever see this new printf trigger?
diff 87962d75d1c1a416b89e927cd4ab8e3327a47509 /usr/src
blob - 58f654273f7ea0cc3c04e0a60d5e5e6a33296dc0
file + sys/net80211/ieee80211_output.c
--- sys/net80211/ieee80211_output.c
+++ sys/net80211/ieee80211_output.c
@@ -556,6 +556,16 @@ ieee80211_encap(struct ifnet *ifp, struct mbuf *m, str
goto bad;
}
+#ifndef IEEE80211_STA_ONLY
+ if (ic->ic_opmode == IEEE80211_M_HOSTAP &&
+ ni->ni_state != IEEE80211_STA_ASSOC) {
+ printf("%s: data frame for node %s in state %d\n",
+ __func__, ether_sprintf(ni->ni_macaddr), ni->ni_state);
+ ic->ic_stats.is_tx_nonode++;
+ goto bad;
+ }
+#endif
+
if ((ic->ic_flags & IEEE80211_F_RSNON) &&
!ni->ni_port_valid &&
eh.ether_type != htons(ETHERTYPE_PAE)) {
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Tue, Apr 27, 2021 at 06:36:32PM +, Mikolaj Kucharski wrote:
> I got it again, but had official snapshot, so I don't have more info
> than I had in the past, but I would like to share it anyway..
> ddb{0}> show panic
> ieee80211_encrypt: key unset for sw crypto: 0
It would be nice to have more information about the bad key.
Could you run with this?
diff 87962d75d1c1a416b89e927cd4ab8e3327a47509 /usr/src
blob - 037aca21138df15a4b0b8ec2a96afd8d67c5e3cc
file + sys/net80211/ieee80211_crypto.c
--- sys/net80211/ieee80211_crypto.c
+++ sys/net80211/ieee80211_crypto.c
@@ -257,8 +257,10 @@ struct mbuf *
ieee80211_encrypt(struct ieee80211com *ic, struct mbuf *m0,
struct ieee80211_key *k)
{
- if ((k->k_flags & IEEE80211_KEY_SWCRYPTO) == 0)
- panic("%s: key unset for sw crypto: %d", __func__, k->k_id);
+ if ((k->k_flags & IEEE80211_KEY_SWCRYPTO) == 0) {
+ panic("%s: key unset for sw crypto: id=%d cipher=%d flags=0x%x",
+ __func__, k->k_id, k->k_cipher, k->k_flags);
+ }
switch (k->k_cipher) {
case IEEE80211_CIPHER_WEP40:
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Mon, Nov 16, 2020 at 01:57:06PM +, Mikolaj Kucharski wrote:
> On Mon, Nov 16, 2020 at 12:53:14PM +0100, Stefan Sperling wrote:
> > On Mon, Nov 16, 2020 at 10:59:45AM +, Mikolaj Kucharski wrote:
> > > It happened again. This time on current. I was on Android phone using
> > > Signal and other laptop on urwn(4) was fetching newest packages snapshot.
> > >
> > > In this email thread it's different physical hardware, but I think
> > > it's same Wi-Fi card like on the other PC Engines board.
> > >
> > > This email thread which I'm continuing here is:
> > >
> > > https://marc.info/?t=16002889984=1=2
> > >
> > > There was also previous one from May 2020:
> > >
> > > https://marc.info/?t=15904785582=1=2
> > >
> > > OpenBSD 6.8-current (GENERIC.MP) #180: Sun Nov 15 18:14:53 MST 2020
> > > dera...@amd64.openbsd.org:/usr/src/sys/arch/amd64/compile/GENERIC.MP
> > >
> >
> > Until a way to trigger this deliberately is found, or we get lucky and
> > someone
> > with time and motivation finds the race by auditing code, there is nothing
> > that
> > could be done here.
>
> Makes sense, Stefan. I don't know how to trigger this on demand,
> but will try to run custom kernel, with some additional debugging
> statements. I will report any panics with new information here.
>
> I have no idea, but looking how usual path is executed if-statement from
> line 1449 is evaluated to true on my machine during usual operation, so
> I imagine when kernel panic happens, probably else branch is executed.
>
> file dev/ic/ar5008.c, function ar5008_tx():
> 1449 if (wh->i_fc[1] & IEEE80211_FC1_PROTECTED) {
> 1450 k = ieee80211_get_txkey(ic, wh, ni);
> 1451 if (k->k_cipher == IEEE80211_CIPHER_CCMP) {
> 1452 u_int hdrlen = ieee80211_get_hdrlen(wh);
> 1453 if (ar5008_ccmp_encap(m, hdrlen, k) != 0)
> 1454 return (ENOBUFS);
> 1455 } else {
> 1456 if ((m = ieee80211_encrypt(ic, m, k)) == NULL)
> 1457 return (ENOBUFS);
> 1458 k = NULL; /* skip hardware crypto further below
> */
> 1459 }
> 1460 wh = mtod(m, struct ieee80211_frame *);
> 1461 }
>
> Anyway, more panics are needed..
>
I got it again, but had official snapshot, so I don't have more info
than I had in the past, but I would like to share it anyway..
OpenBSD 6.9 (GENERIC.MP) #473: Mon Apr 19 10:40:28 MDT 2021
dera...@amd64.openbsd.org:/usr/src/sys/arch/amd64/compile/GENERIC.MP
This is from a remote location, where there is no technical personel.
Basically what I'm trying to say, accesspoint just sits on the shelve
and whoever is in the room has internet access via athn(4) via umb(4).
Only I have (remote) access to that machine and I was not on the machine
at the time of kernel panic.
# /etc/hostname.athn0
mediaopt hostap
nwid SSID_EXAMPLE wpakey PSK_EXAMPLE chan 1
inet 192.168.5.1/24
inet6 autoconf
up
That machine typically runs current, but it just happen upgrade was at
the time when snapshot was pre-release version of OpenBSD. I'm pretty
sure within a month I'll upgrade it to another snapshot and this PC
Engines machine will switch to 6.9-current. I'm trying to semi passively
hunt this kernel panic, and have a debugging kernel with couple of
printf()s to help me better understand this kernel panic, but while
release was approaching I've upgraded to vanilla in search for bugs..
Maybe some additional printf()s could be added to HEAD, to help
understand this rare panic in the future? I still don't know how
to trigger it on demand. It happens rarely and randomly, but I suspect
a Wi-Fi client triggers it, somehow.
ddb{0}> set $lines = 0
ddb{0}> set $maxwidth = 0
ddb{0}> show panic
ieee80211_encrypt: key unset for sw crypto: 0
ddb{0}> trace
db_enter() at db_enter+0x10
panic(81e19763) at panic+0x12a
ieee80211_encrypt(8009c048,fd80cf753200,807f71c0) at
ieee80211_encrypt+0x5f
ar5008_tx(8009c000,fd80cf753200,807f7000,0) at
ar5008_tx+0x163
athn_start(8009c048) at athn_start+0x108
ar5008_intr(8009c000) at ar5008_intr+0x216
intr_handler(8000225a8ad0,8008f780) at intr_handler+0x6e
Xintr_ioapic_level3_untramp() at Xintr_ioapic_level3_untramp+0x193
acpicpu_idle() at acpicpu_idle+0x11f
sched_idle(820d8ff0) at sched_idle+0x27e
end trace frame: 0x0, count: -10
ddb{0}> machine cpuinfo
* 0: ddb
1: stopped
2: stopped
3: stopped
ddb{0}> show registers
rdi 0x820e4bc8kprintf_mutex
rsi 0x5
rbp 0x8000225a8820
rbx 0x8000225a8830
rdx 0xc8000c10
rcx0x202
rax 0x1
r80x8000225a87e0
r9
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Mon, Nov 16, 2020 at 12:53:14PM +0100, Stefan Sperling wrote:
> On Mon, Nov 16, 2020 at 10:59:45AM +, Mikolaj Kucharski wrote:
> > It happened again. This time on current. I was on Android phone using
> > Signal and other laptop on urwn(4) was fetching newest packages snapshot.
> >
> > In this email thread it's different physical hardware, but I think
> > it's same Wi-Fi card like on the other PC Engines board.
> >
> > This email thread which I'm continuing here is:
> >
> > https://marc.info/?t=16002889984=1=2
> >
> > There was also previous one from May 2020:
> >
> > https://marc.info/?t=15904785582=1=2
> >
> > OpenBSD 6.8-current (GENERIC.MP) #180: Sun Nov 15 18:14:53 MST 2020
> > dera...@amd64.openbsd.org:/usr/src/sys/arch/amd64/compile/GENERIC.MP
> >
>
> Until a way to trigger this deliberately is found, or we get lucky and someone
> with time and motivation finds the race by auditing code, there is nothing
> that
> could be done here.
Makes sense, Stefan. I don't know how to trigger this on demand,
but will try to run custom kernel, with some additional debugging
statements. I will report any panics with new information here.
I have no idea, but looking how usual path is executed if-statement from
line 1449 is evaluated to true on my machine during usual operation, so
I imagine when kernel panic happens, probably else branch is executed.
file dev/ic/ar5008.c, function ar5008_tx():
1449 if (wh->i_fc[1] & IEEE80211_FC1_PROTECTED) {
1450 k = ieee80211_get_txkey(ic, wh, ni);
1451 if (k->k_cipher == IEEE80211_CIPHER_CCMP) {
1452 u_int hdrlen = ieee80211_get_hdrlen(wh);
1453 if (ar5008_ccmp_encap(m, hdrlen, k) != 0)
1454 return (ENOBUFS);
1455 } else {
1456 if ((m = ieee80211_encrypt(ic, m, k)) == NULL)
1457 return (ENOBUFS);
1458 k = NULL; /* skip hardware crypto further below */
1459 }
1460 wh = mtod(m, struct ieee80211_frame *);
1461 }
Anyway, more panics are needed..
--
Regards,
Mikolaj
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Mon, Nov 16, 2020 at 10:59:45AM +, Mikolaj Kucharski wrote: > It happened again. This time on current. I was on Android phone using > Signal and other laptop on urwn(4) was fetching newest packages snapshot. > > In this email thread it's different physical hardware, but I think > it's same Wi-Fi card like on the other PC Engines board. > > This email thread which I'm continuing here is: > > https://marc.info/?t=16002889984=1=2 > > There was also previous one from May 2020: > > https://marc.info/?t=15904785582=1=2 > > OpenBSD 6.8-current (GENERIC.MP) #180: Sun Nov 15 18:14:53 MST 2020 > dera...@amd64.openbsd.org:/usr/src/sys/arch/amd64/compile/GENERIC.MP > Until a way to trigger this deliberately is found, or we get lucky and someone with time and motivation finds the race by auditing code, there is nothing that could be done here.
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
It happened again. This time on current. I was on Android phone using
Signal and other laptop on urwn(4) was fetching newest packages snapshot.
In this email thread it's different physical hardware, but I think
it's same Wi-Fi card like on the other PC Engines board.
This email thread which I'm continuing here is:
https://marc.info/?t=16002889984=1=2
There was also previous one from May 2020:
https://marc.info/?t=15904785582=1=2
OpenBSD 6.8-current (GENERIC.MP) #180: Sun Nov 15 18:14:53 MST 2020
dera...@amd64.openbsd.org:/usr/src/sys/arch/amd64/compile/GENERIC.MP
ddb{0}> set $lines = 0
ddb{0}> set $maxwidth = 0
ddb{0}> show panic
ieee80211_encrypt: key unset for sw crypto: 0
ddb{0}> trace
db_enter() at db_enter+0x10
panic(81e090b5) at panic+0x12a
ieee80211_encrypt(8009b048,fd80ab432400,805881c0) at
ieee80211_encrypt+0x5f
ar5008_tx(8009b000,fd80ab432400,80588000,0) at
ar5008_tx+0x179
athn_start(8009b048) at athn_start+0x108
ar5008_intr(8009b000) at ar5008_intr+0x216
intr_handler(8000225a6860,80091500) at intr_handler+0x6e
Xintr_ioapic_level3_untramp() at Xintr_ioapic_level3_untramp+0x193
acpicpu_idle() at acpicpu_idle+0x11f
sched_idle(82111ff0) at sched_idle+0x27e
end trace frame: 0x0, count: -10
ddb{0}> show registers
rdi 0x8210fa50kprintf_mutex
rsi 0x5
rbp 0x8000225a65b0
rbx 0x8000225a65c0
rdx 0xc8000c10
rcx0x202
rax 0x1
r80x8000225a6570
r9 0
r10 0xc691e54969d34a64
r11 0xb33301e8635ee0e9
r12 0x38
r13 0x8000225a6660
r140x100
r15 0x81e090b5pp_r600_decoded_lanes+0xf8a9
rip 0x811ed0f0db_enter+0x10
cs 0x8
rflags 0x282
rsp 0x8000225a65b0
ss 0x10
db_enter+0x10: popq%rbp
ddb{0}> show proc
PROC (idle0) pid=49212 stat=onproc
flags process=14000 proc=4200
pri=0, usrpri=50, nice=20
forw=0xe03a1f594ae0d3a8, list=0x8000f9a0,0x8000f490
process=0x8000d740 user=0x8000225a1000,
vmspace=0x82234ae8
estcpu=0, cpticks=2338387, pctcpu=0.0
user=0, sys=0, intr=0
ddb{0}> ps
PID TID PPIDUID S FLAGS WAIT COMMAND
38041 490119 50825 0 30x100082 nanosleep sleep
42910 409572 71465 0 30x100082 nanosleep sleep
26959 246583 83905 0 30x100082 nanosleep sleep
32647 32823 9131 32767 30x100082 nanosleep sleep
15637 302416 1 0 30x100083 ttyin getty
60212 259555 1 0 30x100098 poll cron
96485 44956 1658 30x80 nanosleep vnstatd
83905 200457 1 0 30x10008b pause sh
71465 441182 1 0 30x10008b pause sh
9131 46906 1 32767 30x10008b pause sh
50825 425578 1 0 30x10008b pause sh
63146 33002 1577 30x90 poll openvpn
29881 410827 1 0 30x100080 kqreadhttpd
98023 157347 1 67 30x100092 kqreadhttpd
25640 298297 1 67 30x100092 kqreadhttpd
277218689 1 67 30x100092 kqreadhttpd
64016 269696 1 67 30x100092 kqreadhttpd
81829 419932 74208 95 30x100092 kqreadsmtpd
49183 278972 74208103 30x100092 kqreadsmtpd
85697 184216 74208 95 30x100092 kqreadsmtpd
5899 431797 74208 95 30x100092 kqreadsmtpd
15469 136005 74208 95 30x100092 kqreadsmtpd
22211 152421 74208 95 30x100092 kqreadsmtpd
74208 114129 1 0 30x100080 kqreadsmtpd
27564 274188 41237 94 30x100092 kqreadrad
58926 154866 41237 94 30x100092 kqreadrad
41237 96990 1 0 30x100080 kqreadrad
34186 152215 1 77 30x100090 poll dhcpd
34592 73519 1 0 30x80 selectsshd
12834 178475 1 0 30x100080 poll ntpd
37624 108154 53325 83 30x100092 poll ntpd
53325 389556 1 83 30x100092 poll ntpd
69007 312091 1 53 30x90 kqreadunbound
16669 378014 21308 73 30x100090 kqreadsyslogd
21308 264327 1 0 30x100082 netio syslogd
985 34345 1 77 30x100090 poll dhclient
10590 272451 1 0 30x80
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Thu, Sep 17, 2020 at 12:31:16PM +0200, Stefan Sperling wrote:
> On Wed, Sep 16, 2020 at 08:39:19PM +, Mikolaj Kucharski wrote:
> > This one seems random, on that machine I see it first time. CVS checkout
> > is basically the build time as I first do cvs up and then make.
>
> We have seen this before, haven't we?
Yes, this happened before.
> This means another race condition exists.
> Are you sure you didn't run any ifconfig commands before this crash occured?
I personally didn't run anything as I was not logged in when the panic
happened. Collection of ddb panic outputs is automated.
However, on that box there are scritps which run ifconfig (without any
arguments) to collect some information when internet is down (umb has
some edge cases when it can loose default geteway and box ends up with
no internet access).
Panic from this report happened at Sep 16 08:22:20 and on OpenBSD I
don't see any problems with internet access at that time in syslog:
2020-09-16T08:21:24.472Z pce-0035 internet-watchdog[45021]: Google server
8.8.4.4 is reachable.
2020-09-16T08:21:24.479Z pce-0035 internet-watchdog[45021]: Sleeping for 180
seconds...
2020-09-16T08:23:38.917Z pce-0035 syslogd[83668]: start
2020-09-16T08:23:38.919Z pce-0035 /bsd: OpenBSD 6.8-beta (GENERIC.MP) #73: Sun
Sep 13 15:23:23 UTC 2020
2020-09-16T08:23:38.919Z pce-0035 /bsd:
r...@pc1.home.local:/home/mkucharski/openbsd/src/sys/arch/amd64/compile/GENERIC.MP
so I don't belive any ifconfig command was executed at the moment of
panic, but I cannot be 100% sure.
However why do you ask about this ifconfig? You want to understand is
this human / userland triggered panic?
> > OpenBSD 6.8-beta (GENERIC.MP) #73: Sun Sep 13 15:23:23 UTC 2020
> >
> > r...@pc1.home.local:/home/mkucharski/openbsd/src/sys/arch/amd64/compile/GENERIC.MP
> >
> > # ls -1 /var/db/pkg/ | grep -e -firmware-
> > athn-firmware-1.1p4
> > vmm-firmware-1.11.0p3
> >
> > panic: ieee80211_encrypt: key unset for sw crypto: 0
> > Stopped at db_enter+0x10: popq%rbp
> > TIDPIDUID PRFLAGS PFLAGS CPU COMMAND
> > db_enter() at db_enter+0x10
> > panic(81e14354) at panic+0x12a
> > ieee80211_encrypt(8009c048,fd80cfe73900,80cab1a8) at
> > ieee80211_encrypt+0x5f
> > ar5008_tx(8009c000,fd80cfe73900,80cab000,0) at
> > ar5008_tx+0x179
> > athn_start(8009c048) at athn_start+0x108
> > ar5008_intr(8009c000) at ar5008_intr+0x216
> > intr_handler(8000225ae400,8008e600) at intr_handler+0x6e
> > Xintr_ioapic_level3_untramp() at Xintr_ioapic_level3_untramp+0x1a3
> > acpicpu_idle() at acpicpu_idle+0x11f
> > sched_idle(820edff0) at sched_idle+0x27e
> > end trace frame: 0x0, count: 5
> > https://www.openbsd.org/ddb.html describes the minimum info required in bug
> > reports. Insufficient info makes it difficult to find and fix bugs.
> > ddb{0}> set $lines = 0
> > ddb{0}> set $maxwidth = 0
> > ddb{0}> show panic
> > ieee80211_encrypt: key unset for sw crypto: 0
> > ddb{0}> trace
> > db_enter() at db_enter+0x10
> > panic(81e14354) at panic+0x12a
> > ieee80211_encrypt(8009c048,fd80cfe73900,80cab1a8) at
> > ieee80211_encrypt+0x5f
> > ar5008_tx(8009c000,fd80cfe73900,80cab000,0) at
> > ar5008_tx+0x179
> > athn_start(8009c048) at athn_start+0x108
> > ar5008_intr(8009c000) at ar5008_intr+0x216
> > intr_handler(8000225ae400,8008e600) at intr_handler+0x6e
> > Xintr_ioapic_level3_untramp() at Xintr_ioapic_level3_untramp+0x1a3
> > acpicpu_idle() at acpicpu_idle+0x11f
> > sched_idle(820edff0) at sched_idle+0x27e
> > end trace frame: 0x0, count: -10
> > ddb{0}> show registers
> > rdi 0x820f80d0kprintf_mutex
> > rsi 0x5
> > rbp 0x8000225ae140
> > rbx 0x8000225ae150
> > rdx 0xc8000c10
> > rcx0x282
> > rax 0x1
> > r80x8000225ae100
> > r9 0
> > r10 0xc01573d4f68d778f
> > r11 0x98ddf1021cc7fae3
> > r12 0x38
> > r13 0x8000225ae1f0
> > r140x100
> > r15 0x81e14354pp_r600_decoded_lanes+0xebac
> > rip 0x81529ce0db_enter+0x10
> > cs 0x8
> > rflags 0x282
> > rsp 0x8000225ae140
> > ss 0x10
> > db_enter+0x10: popq%rbp
> > ddb{0}> show proc
> > PROC (idle0) pid=382939 stat=onproc
> > flags process=14000 proc=4200
> > pri=0, usrpri=50, nice=20
> > forw=0xd7981ee8b12181d4, list=0x8000f8b0,0x8000f158
> > process=0x8000d620 user=0x8000225a9000,
> > vmspace=0x821f2c58
> > estcpu=0,
Re: panic: ieee80211_encrypt: key unset for sw crypto: 0 on 6.8-beta
On Wed, Sep 16, 2020 at 08:39:19PM +, Mikolaj Kucharski wrote:
> This one seems random, on that machine I see it first time. CVS checkout
> is basically the build time as I first do cvs up and then make.
We have seen this before, haven't we?
This means another race condition exists.
Are you sure you didn't run any ifconfig commands before this crash occured?
> OpenBSD 6.8-beta (GENERIC.MP) #73: Sun Sep 13 15:23:23 UTC 2020
>
> r...@pc1.home.local:/home/mkucharski/openbsd/src/sys/arch/amd64/compile/GENERIC.MP
>
> # ls -1 /var/db/pkg/ | grep -e -firmware-
> athn-firmware-1.1p4
> vmm-firmware-1.11.0p3
>
> panic: ieee80211_encrypt: key unset for sw crypto: 0
> Stopped at db_enter+0x10: popq%rbp
> TIDPIDUID PRFLAGS PFLAGS CPU COMMAND
> db_enter() at db_enter+0x10
> panic(81e14354) at panic+0x12a
> ieee80211_encrypt(8009c048,fd80cfe73900,80cab1a8) at
> ieee80211_encrypt+0x5f
> ar5008_tx(8009c000,fd80cfe73900,80cab000,0) at
> ar5008_tx+0x179
> athn_start(8009c048) at athn_start+0x108
> ar5008_intr(8009c000) at ar5008_intr+0x216
> intr_handler(8000225ae400,8008e600) at intr_handler+0x6e
> Xintr_ioapic_level3_untramp() at Xintr_ioapic_level3_untramp+0x1a3
> acpicpu_idle() at acpicpu_idle+0x11f
> sched_idle(820edff0) at sched_idle+0x27e
> end trace frame: 0x0, count: 5
> https://www.openbsd.org/ddb.html describes the minimum info required in bug
> reports. Insufficient info makes it difficult to find and fix bugs.
> ddb{0}> set $lines = 0
> ddb{0}> set $maxwidth = 0
> ddb{0}> show panic
> ieee80211_encrypt: key unset for sw crypto: 0
> ddb{0}> trace
> db_enter() at db_enter+0x10
> panic(81e14354) at panic+0x12a
> ieee80211_encrypt(8009c048,fd80cfe73900,80cab1a8) at
> ieee80211_encrypt+0x5f
> ar5008_tx(8009c000,fd80cfe73900,80cab000,0) at
> ar5008_tx+0x179
> athn_start(8009c048) at athn_start+0x108
> ar5008_intr(8009c000) at ar5008_intr+0x216
> intr_handler(8000225ae400,8008e600) at intr_handler+0x6e
> Xintr_ioapic_level3_untramp() at Xintr_ioapic_level3_untramp+0x1a3
> acpicpu_idle() at acpicpu_idle+0x11f
> sched_idle(820edff0) at sched_idle+0x27e
> end trace frame: 0x0, count: -10
> ddb{0}> show registers
> rdi 0x820f80d0kprintf_mutex
> rsi 0x5
> rbp 0x8000225ae140
> rbx 0x8000225ae150
> rdx 0xc8000c10
> rcx0x282
> rax 0x1
> r80x8000225ae100
> r9 0
> r10 0xc01573d4f68d778f
> r11 0x98ddf1021cc7fae3
> r12 0x38
> r13 0x8000225ae1f0
> r140x100
> r15 0x81e14354pp_r600_decoded_lanes+0xebac
> rip 0x81529ce0db_enter+0x10
> cs 0x8
> rflags 0x282
> rsp 0x8000225ae140
> ss 0x10
> db_enter+0x10: popq%rbp
> ddb{0}> show proc
> PROC (idle0) pid=382939 stat=onproc
> flags process=14000 proc=4200
> pri=0, usrpri=50, nice=20
> forw=0xd7981ee8b12181d4, list=0x8000f8b0,0x8000f158
> process=0x8000d620 user=0x8000225a9000,
> vmspace=0x821f2c58
> estcpu=0, cpticks=23009481, pctcpu=0.0
> user=0, sys=0, intr=1
> ddb{0}> ps
>PID TID PPIDUID S FLAGS WAIT COMMAND
> 53424 57045 38449 0 30x100082 nanosleep sleep
> 50116 356838 45021 0 30x100082 nanosleep sleep
> 22526 215536 10762 0 30x100083 ttyin ksh
> 75173 305461 1577 30x90 poll openvpn
> 58097 185498 10762 0 30x100083 ttyin ksh
> 10762 118644 1 0 30x100080 kqreadtmux
> 18237 308163 1 0 30x100083 ttyin getty
> 88227 59324 1 0 30x100098 poll cron
> 89706 370738 1 0 30x100080 htplevhotplugd
> 45021 254474 1 0 30x10008b pause sh
> 7678 418133 1 0 30x82 kqreadcupsd
> 41143 215752 1572 30x90 poll dbus-daemon
> 38449 510863 1 0 30x10008b pause sh
> 17512 407584 47024 95 30x100092 kqreadsmtpd
> 80599 455578 47024103 30x100092 kqreadsmtpd
> 82543 213560 47024 95 30x100092 kqreadsmtpd
> 99925 364250 47024 95 30x100092 kqreadsmtpd
> 76184 140593 47024 95 30x100092 kqreadsmtpd
> 68500 323266 47024 95 30x100092 kqreadsmtpd
> 47024 294473 1 0 30x100080
