On Tue, May 26, 2020 at 11:16:30AM +0000, Mikolaj Kucharski wrote:
> On Tue, May 26, 2020 at 10:37:09AM +0200, Stefan Sperling wrote:
> >
> > I don't yet have a definite idea what could cause this.
> > I did however notice a problem which may be related. Could you try this
> > diff?
>
> I'm running below diff, with small change:
>
> if (rekeysta == 0) {
> printf("XXX %s() [%s|%d] rekeysta == 0\n", __FUNCTION__,
> __FILE__, __LINE__);
> ieee80211_setkeysdone(ic);
> }
>
> Access point has a bit over 1 hour of uptime and so far no XXX entries
> in dmesg nor in /var/log/messages.
Uptime of 3h37m with following two entries (from dmesg):
c0:ee:fb:33:f0:11: mira sfer > 1
c0:ee:fb:33:f0:11: mira sfer > 1
c0:ee:fb:33:f0:11: mira sfer > 1
athn0: sending msg 1/2 of the group key handshake to c0:ee:fb:33:f0:11
XXX ieee80211_setkeys()
[/home/mkucharski/openbsd/src/sys/net80211/ieee80211_proto.c|463] rekeysta == 0
athn0: received msg 2/2 of the group key handshake from c0:ee:fb:33:f0:11
c0:ee:fb:33:f0:11: mira sfer > 1
c0:ee:fb:33:f0:11: mira sfer > 1
athn0: station 38:d5:47:b1:e4:3c purged from node cache
c0:ee:fb:33:f0:11: mira sfer > 1
c0:ee:fb:33:f0:11: mira sfer > 1
c0:ee:fb:33:f0:11: mira sfer > 1
c0:ee:fb:33:f0:11: mira sfer > 1
...
c0:ee:fb:33:f0:11: mira sfer > 1
c0:ee:fb:33:f0:11: mira sfer > 1
c0:ee:fb:33:f0:11: mira sfer > 1
c0:ee:fb:33:f0:11: mira sfer > 1
athn0: sending msg 1/2 of the group key handshake to c0:ee:fb:33:f0:11
XXX ieee80211_setkeys()
[/home/mkucharski/openbsd/src/sys/net80211/ieee80211_proto.c|463] rekeysta == 0
athn0: sending msg 1/2 of the group key handshake to c0:ee:fb:33:f0:11
athn0: sending msg 1/2 of the group key handshake to c0:ee:fb:33:f0:11
athn0: station c0:ee:fb:33:f0:11 deauthenticate (reason 16)
athn0: sending deauth to c0:ee:fb:33:f0:11 on channel 13 mode 11n
athn0: sending auth to c0:ee:fb:33:f0:11 on channel 13 mode 11n
athn0: station c0:ee:fb:33:f0:11 newly authenticated (open)
athn0: sending assoc_resp to c0:ee:fb:33:f0:11 on channel 13 mode 11n
athn0: sending msg 1/4 of the 4-way handshake to c0:ee:fb:33:f0:11
athn0: received msg 2/4 of the 4-way handshake from c0:ee:fb:33:f0:11
athn0: sending msg 3/4 of the 4-way handshake to c0:ee:fb:33:f0:11
athn0: received msg 4/4 of the 4-way handshake from c0:ee:fb:33:f0:11
c0:ee:fb:33:f0:11: mira sfer > 1
athn0: sending action to c0:ee:fb:33:f0:11 on channel 13 mode 11n
c0:ee:fb:33:f0:11: mira sfer > 1
# grep -w XXX /var/log/messages
2020-05-26T12:04:39.131Z pce-0041 /bsd: XXX ieee80211_setkeys()
[/home/mkucharski/openbsd/src/sys/net80211/ieee80211_proto.c|463] rekeysta == 0
2020-05-26T13:04:39.520Z pce-0041 /bsd: XXX ieee80211_setkeys()
[/home/mkucharski/openbsd/src/sys/net80211/ieee80211_proto.c|463] rekeysta == 0
> I will leave it for couple of days. If you want me to run your vanilla
> diff and to remove above printf I can do that, no problem.
>
> > diff 3247d7f3b53b75bbaf4356f06f34208638ba213d /usr/src
> > blob - b44405af41448849059a4558c55bd182f823c1df
> > file + sys/net80211/ieee80211_proto.c
> > --- sys/net80211/ieee80211_proto.c
> > +++ sys/net80211/ieee80211_proto.c
> > @@ -433,6 +433,7 @@ ieee80211_setkeys(struct ieee80211com *ic)
> > {
> > struct ieee80211_key *k;
> > u_int8_t kid;
> > + int rekeysta;
> >
> > /* Swap(GM, GN) */
> > kid = (ic->ic_def_txkey == 1) ? 2 : 1;
> > @@ -457,6 +458,9 @@ ieee80211_setkeys(struct ieee80211com *ic)
> > }
> >
> > ieee80211_iterate_nodes(ic, ieee80211_node_gtk_rekey, ic);
> > + ieee80211_iterate_nodes(ic, ieee80211_count_rekeysta, &rekeysta);
> > + if (rekeysta == 0)
> > + ieee80211_setkeysdone(ic);
> > }
> >
> > /*
> > @@ -466,6 +470,12 @@ void
> > ieee80211_setkeysdone(struct ieee80211com *ic)
> > {
> > u_int8_t kid;
> > +
> > + /*
> > + * Discard frames buffered for power-saving which were encrypted with
> > + * the old group key. Clients are no longer able to decrypt them.
> > + */
> > + mq_purge(&ic->ic_bss->ni_savedq);
> >
> > /* install GTK */
> > kid = (ic->ic_def_txkey == 1) ? 2 : 1;
>
--
Regards,
Mikolaj
