[Prism54-devel] Re: islpci_mgt_transaction and stability

Denis Vlasenko vda at port.imtp.ilyichevsk.odessa.ua
Mon Aug 9 19:45:41 UTC 2004


> > But I noticed one interesting thing. Whenever link is restored,
> > I see lone "islpci_mgt_transaction(op 0, oid 10000001, sendlen 6)"
> > in syslog. What that can be?
> >
> > oid_mgt.c:
> >         OID_STRUCT_C(DOT11_OID_BSSID, 0x10000001, u8[6], OID_TYPE_RAW),
> >
> > I wonder, is this the result of (re)assoc happened?
> > Or maybe it is other way around and this transaction kicked hw so
> > that hw noticed the problem and reassociated?
>
> Hmm, strange indeed. My only guess would be a bogus call to
> mgt_get_request where the "extra" parameter was set to some value it
> shouldn't have. When extra is set, the oid used for the get can be
> affected by:
>
> oid = isl_oid[n].oid + extra;
>
> Perhaps try printk'ing extra here for all gets see if that triggered it

I'll give dump_stack() a try instead ;)

Okay, now, another reproducible weird situation.

In the same setup, I configure both STA and AP with set_rates 1,2,5,11
and do my favorite UDP flood. It can run for tens of minutes, sometimes
STA is losing assoc and restoring it, as described in prev mail.

If I do not run "watch iwconfig", it does not get mgt timeouts.
I also disqualify any tests where I've seen tx timeouts
(because reset code do not know how to restore rate sets yet).

Sooner or later STA loses assoc and cannot restore it anymore.
I have wireless shiffer, this is log from it:

22:20:03.310383 0us Probe Request (zzz) [1.0 2.0 5.5 11.0 Mbit]
22:20:03.311656 6us Acknowledgment RA:00:04:e2:64:15:e5
22:20:03.464326 314us Authentication (Open System)-1: Succesful
22:20:03.465374 Retry 314us Authentication (Open System)-1: Succesful
22:20:03.467203 Retry 314us Authentication (Open System)-1: Succesful
22:20:03.468936 Retry 314us Authentication (Open System)-1: Succesful
22:20:03.471061 Retry 314us Authentication (Open System)-1: Succesful
22:20:03.478671 Retry 314us Authentication (Open System)-1: Succesful
22:20:03.493965 Retry 314us Authentication (Open System)-1: Succesful
22:20:03.497637 Retry 314us Authentication (Open System)-1: Succesful
22:20:16.321884 0us Probe Request (zzz) [1.0 2.0 5.5 11.0 Mbit]
22:20:16.781663 314us Authentication (Open System)-1: Succesful
22:20:16.782885 Retry 314us Authentication (Open System)-1: Succesful
22:20:16.784514 Retry 314us Authentication (Open System)-1: Succesful
22:20:16.787353 Retry 314us Authentication (Open System)-1: Succesful
22:20:16.790495 Retry 314us Authentication (Open System)-1: Succesful
22:20:16.794422 Retry 314us Authentication (Open System)-1: Succesful
22:20:16.816347 Retry 314us Authentication (Open System)-1: Succesful
22:20:16.834336 Retry 314us Authentication (Open System)-1: Succesful
22:20:16.835477 6us Acknowledgment RA:00:04:e2:64:15:e5
22:20:16.836245 314us Assoc Request (zzz) [1.0 2.0 5.5 11.0 Mbit]
22:20:16.837427 Retry 314us Assoc Request (zzz) [1.0 2.0 5.5 11.0 Mbit]
22:20:16.839389 Retry 314us Assoc Request (zzz) [1.0 2.0 5.5 11.0 Mbit]
22:20:16.840370 Retry 314us Assoc Request (zzz) [1.0 2.0 5.5 11.0 Mbit]
22:20:16.843430 Retry 314us Assoc Request (zzz) [1.0 2.0 5.5 11.0 Mbit]
22:20:16.850093 Retry 314us Assoc Request (zzz) [1.0 2.0 5.5 11.0 Mbit]
22:20:16.860937 Retry 314us Assoc Request (zzz) [1.0 2.0 5.5 11.0 Mbit]
22:20:16.881779 Retry 314us Assoc Request (zzz) [1.0 2.0 5.5 11.0 Mbit]

ad infinitum.

If I run iwconfig <iface> set_rates 1,2,5,11 on AP _again_, 
STA recovers within 5 seconds, here's the log:

22:20:40.869509 314us Authentication (Open System)-1: Succesful
22:20:40.870649 Retry 314us Authentication (Open System)-1: Succesful
22:20:40.871898 Retry 314us Authentication (Open System)-1: Succesful
22:20:40.874626 Retry 314us Authentication (Open System)-1: Succesful
22:20:40.880052 Retry 314us Authentication (Open System)-1: Succesful
22:20:40.881225 Retry 314us Authentication (Open System)-1: Succesful
22:20:40.893001 Retry 314us Authentication (Open System)-1: Succesful
22:20:40.902384 Retry 314us Authentication (Open System)-1: Succesful
22:20:42.664655 314us Authentication (Open System)-1: Succesful
22:20:42.665796 Retry 314us Authentication (Open System)-1: Succesful
22:20:42.667104 Retry 314us Authentication (Open System)-1: Succesful
22:20:42.668874 Retry 314us Authentication (Open System)-1: Succesful
22:20:42.672705 Retry 314us Authentication (Open System)-1: Succesful
22:20:42.674091 Retry 314us Authentication (Open System)-1: Succesful
22:20:42.681245 Retry 314us Authentication (Open System)-1: Succesful
22:20:42.694357 Retry 314us Authentication (Open System)-1: Succesful
22:20:44.305758 0us Probe Request (zzz) [1.0 2.0 5.5 11.0 Mbit]
22:20:44.459684 314us Authentication (Open System)-1: Succesful
22:20:44.460829 6us Acknowledgment RA:00:04:e2:64:15:e5
22:20:44.461462 314us Assoc Request (zzz) [1.0 2.0 5.5 11.0 Mbit]
22:20:44.462647 6us Acknowledgment RA:00:04:e2:64:15:e5
22:20:44.604852 168us snap 0:0:0:8:6 arp who-has 1.3.3.2 tell 1.3.3.1
22:20:44.612097 0us Acknowledgment RA:00:04:e2:64:15:e5
22:20:44.618696 0us Acknowledgment RA:00:04:e2:64:15:e5
22:20:44.622486 0us Acknowledgment RA:00:04:e2:64:15:e5
22:20:44.623377 0us Acknowledgment RA:00:04:e2:64:15:e5
22:20:44.629821 0us Acknowledgment RA:00:04:e2:64:15:e5
22:20:44.636808 168us snap 0:0:0:8:0 IP (tos 0x0, ttl  64, id 43069, offset 5920, flags [+], length: 1500) 1.3.3.1 > 1.3.3.2: udp
22:20:44.640296 168us snap 0:0:0:8:0 IP (tos 0x0, ttl  64, id 43069, offset 7400, flags [none], length: 820) 1.3.3.1 > 1.3.3.2: udp
22:20:44.653703 168us snap 0:0:0:8:0 IP (tos 0x0, ttl  64, id 43070, offset 1480, flags [+], length: 1500) 1.3.3.1 > 1.3.3.2: udp
22:20:44.660097 168us snap 0:0:0:8:0 IP (tos 0x0, ttl  64, id 43070, offset 2960, flags [+], length: 1500) 1.3.3.1 > 1.3.3.2: udp
22:20:44.666605 168us snap 0:0:0:8:0 IP (tos 0x0, ttl  64, id 43070, offset 4440, flags [+], length: 1500) 1.3.3.1 > 1.3.3.2: udp
22:20:44.672304 0us Acknowledgment RA:00:04:e2:64:15:e5
22:20:44.678767 0us Acknowledgment RA:00:04:e2:64:15:e5
22:20:44.685323 0us Acknowledgment RA:00:04:e2:64:15:e5
22:20:44.692434 Retry 168us snap 0:0:0:8:0 IP (tos 0x0, ttl  64, id 43070, offset 4440, flags [+], length: 1500) 1.3.3.1 > 1.3.3.2: udp
22:20:44.699108 168us snap 0:0:0:8:0 IP (tos 0x0, ttl  64, id 43070, offset 5920, flags [+], length: 1500) 1.3.3.1 > 1.3.3.2: udp
22:20:44.702430 168us snap 0:0:0:8:0 IP (tos 0x0, ttl  64, id 43070, offset 7400, flags [none], length: 820) 1.3.3.1 > 1.3.3.2: udp
22:20:44.709214 168us snap 0:0:0:8:0 IP (tos 0x0, ttl  64, id 43071, offset 0, flags [+], length: 1500) 1.3.3.1.1234 > 1.3.3.2.1024: [bad udp
cksum 401a!] UDP, length: 8192
....

NB: sniffer does not hear AP as good as it hears STA. Some AP packets
are probably went unseen.

For easy reference, here is what set_rates does:

Aug 10 01:32:04 ghost kernel: islpci_mgt_transaction(op 0, oid 17000010, sendlen 21)
Aug 10 01:32:04 ghost kernel: islpci_mgt_transaction(op 1, oid 17000019, sendlen 4)
Aug 10 01:32:04 ghost kernel: islpci_mgt_transaction(op 1, oid 17000020, sendlen 21)
Aug 10 01:32:04 ghost kernel: islpci_mgt_transaction(op 1, oid 1700000a, sendlen 21)

Code is below the sig. After "set_rates 1,2,5,11":

# iwpriv ifp g_rates
ifp       g_rates:hex data=82:84:8B:96:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:
# iwpriv ifp g_extrates
ifp       g_extrates:hex data=00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:10:00:00:00:0F:00:

What this can be? I tried "iwpriv <iface> s_preamble -1", it does not have such
"awakening" effect.

Shall we run set_rates equivalent periodically from a timer?
--
vda

static int
prism54_set_rates(struct net_device *ndev, struct iw_request_info *info,
                struct iw_point *data, char *extra)
{
        union oid_res_t r;
        islpci_private *priv = netdev_priv(ndev);
        int ret;
        u32 profile;
        u8 brate[IWMAX_BITRATES+1];
        u8 erate[IWMAX_BITRATES+1];
        u8 zerobyte = 0;

        ret = mgt_get_request(priv, DOT11_OID_SUPPORTEDRATES, 0, NULL, &r);
        if(ret) return ret;

        ret = fill_ratevectors(extra, brate, erate, IWMAX_BITRATES+1, prism54_supported, r.ptr);
        if(ret) return ret;

        if( strlen((char*)brate)+strlen((char*)erate) > IWMAX_BITRATES )
                return -EINVAL;

        profile = -1;
        ret = mgt_set_request(priv, DOT11_OID_PROFILES, 0, &profile);
        /* peculiar: remove line below - and sometimes ext rates
        will be erroneously advertised as basic: */
        if(!ret)
                ret = mgt_set_request(priv, DOT11_OID_EXTENDEDRATES, 0, &zerobyte);
        /* add ext rates to basic, or else ext rates won't be advertised: */
        strcat((char*)brate,(char*)erate);
        if(!ret)
                ret = mgt_set_request(priv, DOT11_OID_RATES, 0, brate);
        /* I didn't test whether this is needed at all: */
        if(!ret && erate[0])
                ret = mgt_set_request(priv, DOT11_OID_EXTENDEDRATES, 0, erate);

        kfree(r.ptr);

        return ret;
}



More information about the Prism54-devel mailing list