Hi,
It's been now some time since I started hacking on drivers for the AR9170
chipset based cards. I initially wanted to enable wireless link capacity
estimation (in terms of attainable throughput), based on the measurement of
data frame service time. In other words, I wanted to measure the time it
takes the card to fully process each frame it receives from upper layers, from
the instant it first considers the frame for transmission until the instant
when the frame is considered processed (reception of ACK for unicast or end of
transmission for multicast).
What I ended up doing was to modify the carl9170 firmware to enable the card
itself to do the measurement and report that value back along the TX status.
The most important question is about struct carl9170_tx_status. Is it safe to
simply add a u32 duration field and update the CARL9170_TX_STATUS_SIZE to 6?
After quite some testing, it appears that as soon as I change the size of that
struct, I start getting things like this (on any recent kernel with recent
driver+firmware):
usb 1-1: no command feedback received (-110).
carl9170 cmd: 08 01 00 00 f0 36 1c 00 00 24 00 00 .....6...$..
usb 1-1: restart device (6)
ieee80211 phy0: writing reg 0x1c36f0 (val 0x2400) failed (-110)
usb 1-1: device restarted successfully.
------------[ cut here ]------------
WARNING: at /build/buildd/linux-2.6.35/kernel/workqueue.c:495 flush_cpu_workqueue+0x7a/0x80()
...
Modules linked in: carl9170 mac80211 led_class ath cfg80211 compat ...
Call Trace:
[<c014a812>] warn_slowpath_common+0x72/0xa0
[<c016199a>] ? flush_cpu_workqueue+0x7a/0x80
[<c016199a>] ? flush_cpu_workqueue+0x7a/0x80
[<c014a862>] warn_slowpath_null+0x22/0x30
[<c016199a>] flush_cpu_workqueue+0x7a/0x80
[<c01620ee>] flush_workqueue+0x3e/0x60
[<db90f699>] ieee80211_restart_hw+0x19/0x80 [mac80211]
[<db872d92>] carl9170_restart_work+0xc2/0x150 [carl9170]
[<c016155e>] run_workqueue+0x8e/0x150
[<db872cd0>] ? carl9170_restart_work+0x0/0x150 [carl9170]
[<c01616a4>] worker_thread+0x84/0xe0
[<c0165920>] ? autoremove_wake_function+0x0/0x50
[<c0161620>] ? worker_thread+0x0/0xe0
[<c01654f4>] kthread+0x74/0x80
[<c0165480>] ? kthread+0x0/0x80
[<c010363e>] kernel_thread_helper+0x6/0x10
--[ end trace 163c2ca4bc44c139 ]---
At first glance, it seems to be the result of a reentrant call of
flush_workqueue.
If the size of struct tx_status has to remain 2, is there any easy and safe
way to push that duration calculation back towards the driver without
sacrifying the actual information that is useful for the ratecontrol
algorithm?
Thanks you.
Ignacy
--
If you're not living on the edge, you're taking up too much space.
On Tue, Sep 28, 2010 at 01:01:37AM +0200, thus spake Ignacy Gawedzki:
> Yeah, sorry for the vagueness, I promise I'll grab as much info as possible
> upon next encounter of such a thing. As I remember it, it's mainly a matter
> of the module getting suck somehow (and attempts to unload it getting stuck as
> well) and the card not being detected upon subsequent insertions anymore.
And while writing that email, I left the card plugged in the USB socket. In
the meantime, I got the following:
usb 5-1: no command feedback received (-110).
carl9170 cmd: 08 01 00 00 04 40 1d 00 00 00 00 00 .....@......
usb 5-1: restart device (6)
ieee80211 phy1: writing reg 0x1d4004 (val 0x0) failed (-110)
usb 5-1: device restarted successfully.
Then when I unplugged it:
usb 5-1: USB disconnect, address 11
And finally upon modprobe -r carl9170:
usbcore: deregistering interface driver carl9170
And now modprobe is stuck in D+. :/
I now wonder how that could possibly be due to my modifications in the driver
and mac80211 (in a nutshell: retrieve the measurement per frame from the FW
and collect it into a stats structure in the sta descriptor, which is later
retrieved from userspace through netlink). I'll try without these and report
back if that still happens.
Thanks again.
Ignacy
--
:wq!
On Mon, Sep 27, 2010 at 07:36:21PM +0200, thus spake Christian Lamparter:
> Sure, but why when you have a monotonic 40 MHz timer?
Glad to know there is such a thing, then. =)
> (It isn't so much what you do in the firmware, as long as you don't put
> printk into the drivers hot-paths)
>
> > > (Haven't seen the WARN before, kernel/workqueue.c code has changed a lot
> > > and flush_cpu_workqueue is no more...)
> >
> > OK, I'll stick with the latest wireless-testing then. BTW, I noticed that the
> > FW API is 1.8.8.2, while driver API in wireless-testing is still 1.8.8.1.
> Actually, the firmware is already at 1.8.8.3-pre. But it shouldn't matter if
> what API "version" you are using, as long as the firmware descriptors and
> command interface structs are the same.
Okay, I thought these API versions were there to be checked by the driver
somehow for conformance.
> > Having some stability issues with this combination, I reverted the last few
> > commits in the FW's git back to API 1.8.8.1. Are these different numbers
> > nevertheless compatible with each other?
> "Stability issues"? Again, a "vague" and stretchy term. Do you have "Oops" -
> reports or something like that?
Yeah, sorry for the vagueness, I promise I'll grab as much info as possible
upon next encounter of such a thing. As I remember it, it's mainly a matter
of the module getting suck somehow (and attempts to unload it getting stuck as
well) and the card not being detected upon subsequent insertions anymore.
I just tried the whole setup with the latest wireless-testing sources and your
patch on the firmware. So far, so good, the problems I had previously are not
showing up. I'm now just adapting your proposition to support rollover and
conversion of the measurement to nanoseconds.
One last question about your patch. If a frame transmission fails altogether,
i.e. the maximum attempts have been made and no ACK has been received
whatsoever, will the driver get a tx_status with the overall timer spent
serving that frame anyway (read: that's what I actually want)?
Great thanks for your help.
Kind regards,
Ignacy
--
/* This is not a comment */
On Tuesday 28 September 2010 01:23:57 Ignacy Gawedzki wrote:
> And while writing that email, I left the card plugged in the USB socket. In
> the meantime, I got the following:
>
> usb 5-1: no command feedback received (-110).
> carl9170 cmd: 08 01 00 00 04 40 1d 00 00 00 00 00 .....@......
> usb 5-1: restart device (6)
> ieee80211 phy1: writing reg 0x1d4004 (val 0x0) failed (-110)
> usb 5-1: device restarted successfully.
>
> Then when I unplugged it:
>
> usb 5-1: USB disconnect, address 11
>
> And finally upon modprobe -r carl9170:
>
> usbcore: deregistering interface driver carl9170
>
> And now modprobe is stuck in D+. :/
yup, this should be fixed by "[PATCH] carl9170: fix hung workqueue".
> I now wonder how that could possibly be due to my modifications in the driver
> and mac80211 (in a nutshell: retrieve the measurement per frame from the FW
> and collect it into a stats structure in the sta descriptor, which is later
> retrieved from userspace through netlink). I'll try without these and report
> back if that still happens.
hm, you could also add a "custom" RADIO_TAP field. This way you could use
wireshark to monitor the round trip times for each individual frame
(this way you could also export the frames' duration + tx vectors too)
Regards,
Christian
On Mon, Sep 27, 2010 at 05:37:16PM +0200, thus spake Christian Lamparter:
> Sounds familiar, David H. Lynch Jr. <[email protected]> wanted to do the same,
> on the same hardware with same software kit. But as far as I know he abandoned
> the project because the hardware does support the RT interrupts he was
> hoping for.
Yes, i read the whole thread at the time with some interest, as I then noticed
the existence of carl9170. =)
> [...]
> without any problems. The device was able to connect and send a few gigs.
> Maybe you should be a bit more "precise" about your changes ;).
Sure, see the attached diff. The idea is to simply use the local TSF counter
to measure the service time. I know that the TSF gets updated in IBSS pretty
regularly, but still, the measurements seem accurate enough.
> Wait, wait wait 2.6.35? Every kernel before 2.6.35.2 (and a few other
> -stable release) have a serious threading-bug in the usb subsystem.
> I strongly recommend that you update your code-base to the
> latest wireless-testing.
I tried many different versions. Until recently, I was used to getting the
latest wireless-testing revision, apply the patches and compile a fresh
kernel. Now I simply get the latest wireless-testing since carl9170 is now
included in there. The exerpt is from a test in which I took the Ubuntu
Maverick kernel and compiled the latest compat-wireless package after applying
my own modifications.
> (Haven't seen the WARN before, kernel/workqueue.c code has changed a lot
> and flush_cpu_workqueue is no more...)
OK, I'll stick with the latest wireless-testing then. BTW, I noticed that the
FW API is 1.8.8.2, while driver API in wireless-testing is still 1.8.8.1.
Having some stability issues with this combination, I reverted the last few
commits in the FW's git back to API 1.8.8.1. Are these different numbers
nevertheless compatible with each other?
Thanks so much for your help.
Best regards,
Ignacy
--
I used to have a sig, but I've stopped smoking now.
On Tuesday 28 September 2010 08:27:21 Ignacy Gawedzki wrote:
> On Tue, Sep 28, 2010 at 01:28:22AM +0200, thus spake Christian Lamparter:
> > On Tuesday 28 September 2010 01:01:37 Ignacy Gawedzki wrote:
> > > On Mon, Sep 27, 2010 at 07:36:21PM +0200, thus spake Christian Lamparter:
> > > > Sure, but why when you have a monotonic 40 MHz timer?
> > >
> > > Glad to know there is such a thing, then. =)
> > or was it 80Mhz? Nevermind, the docs are not very specific.
>
> AFAICT there's a constant in timer.h :
>
> #define AR9170_TICKS_PER_MICROSECOND 80
it is supposed to be 25 ns clock counter
> but there's also that clock_set() function that seems to be setting the clock
> up with different frequencies, but I supppose that's a different thing.
clock_set sets the CPUs clock, which has an effect on timer0-3 but not
on the clock source.
> > > I just tried the whole setup with the latest wireless-testing sources and your
> > > patch on the firmware. So far, so good, the problems I had previously are not
> > > showing up. I'm now just adapting your proposition to support rollover and
> > > conversion of the measurement to nanoseconds.
> > Rollover checks? Can you please tell me where you exactly see a potential
> > rollover problem in the proposal?
>
> Well, what I meant was to support the case when the clock ticks counter wraps
> around. Supposing there are 40e6 ticks per second, 2^32 ticks run out in less
> than 108 seconds, or maybe I'm missing something here.
yes, "MAC RESET" and carl9170_tx_janitor. A frame can't be delayed for more
than 6 second.
> I then need to consider the case where comp_tsf ends up not being larger
> than tsfl. Since > we're dealing with unsigned ints, in this case the
> simple difference would end up being something rather large. :/
Too much bad literature.
Give it a try, set comp_tsfl = 0x10 and super->s.tsfl = 0xfffff000.
then comp_tsfl - super->s.tsfl equals to 0x10 - 0xfffff000, which on
a 32-bit arch gives you 0x00001010 (+ carry/borrow)
Regards,
Chr
On Monday 27 September 2010 18:05:57 Ignacy Gawedzki wrote:
> On Mon, Sep 27, 2010 at 05:37:16PM +0200, thus spake Christian Lamparter:
> > [...]
> > without any problems. The device was able to connect and send a few gigs.
> > Maybe you should be a bit more "precise" about your changes ;).
>
> Sure, see the attached diff. The idea is to simply use the local TSF counter
> to measure the service time. I know that the TSF gets updated in IBSS pretty
> regularly, but still, the measurements seem accurate enough.
Sure, but why when you have a monotonic 40 MHz timer?
(It isn't so much what you do in the firmware, as long as you don't put
printk into the drivers hot-paths)
> > (Haven't seen the WARN before, kernel/workqueue.c code has changed a lot
> > and flush_cpu_workqueue is no more...)
>
> OK, I'll stick with the latest wireless-testing then. BTW, I noticed that the
> FW API is 1.8.8.2, while driver API in wireless-testing is still 1.8.8.1.
Actually, the firmware is already at 1.8.8.3-pre. But it shouldn't matter if
what API "version" you are using, as long as the firmware descriptors and
command interface structs are the same.
> Having some stability issues with this combination, I reverted the last few
> commits in the FW's git back to API 1.8.8.1. Are these different numbers
> nevertheless compatible with each other?
"Stability issues"? Again, a "vague" and stretchy term. Do you have "Oops" -
reports or something like that?
Regards,
Chr
On Tue, Sep 28, 2010 at 02:04:59PM +0200, thus spake Christian Lamparter:
> On Tuesday 28 September 2010 08:27:21 Ignacy Gawedzki wrote:
> > AFAICT there's a constant in timer.h :
> >
> > #define AR9170_TICKS_PER_MICROSECOND 80
> it is supposed to be 25 ns clock counter
I don't get what you mean by that. Is anything wrong with this constant?
> clock_set sets the CPUs clock, which has an effect on timer0-3 but not
> on the clock source.
Ah okay, very well.
> > I then need to consider the case where comp_tsf ends up not being larger
> > than tsfl. Since > we're dealing with unsigned ints, in this case the
> > simple difference would end up being something rather large. :/
> Too much bad literature.
In my case that must be too little literature overall.
> Give it a try, set comp_tsfl = 0x10 and super->s.tsfl = 0xfffff000.
> then comp_tsfl - super->s.tsfl equals to 0x10 - 0xfffff000, which on
> a 32-bit arch gives you 0x00001010 (+ carry/borrow)
Ha ha... shame on me. =)
Thanks for the lesson, master.
Regards,
Ignacy
--
A person is shit's way of making more shit.
-- S. Barnett, anthropologist.
On Tuesday 28 September 2010 01:01:37 Ignacy Gawedzki wrote:
> On Mon, Sep 27, 2010 at 07:36:21PM +0200, thus spake Christian Lamparter:
> > Sure, but why when you have a monotonic 40 MHz timer?
>
> Glad to know there is such a thing, then. =)
or was it 80Mhz? Nevermind, the docs are not very specific.
> > > OK, I'll stick with the latest wireless-testing then. BTW, I noticed that the
> > > FW API is 1.8.8.2, while driver API in wireless-testing is still 1.8.8.1.
> > Actually, the firmware is already at 1.8.8.3-pre. But it shouldn't matter if
> > what API "version" you are using, as long as the firmware descriptors and
> > command interface structs are the same.
>
> Okay, I thought these API versions were there to be checked by the driver
> somehow for conformance.
They are... But only at the "highest" level ;)
Anyway, there's a bitfield which describe what commands, operation modes
and features are support by the firmware image.
> > > Having some stability issues with this combination, I reverted the last few
> > > commits in the FW's git back to API 1.8.8.1. Are these different numbers
> > > nevertheless compatible with each other?
> > "Stability issues"? Again, a "vague" and stretchy term. Do you have "Oops" -
> > reports or something like that?
>
> Yeah, sorry for the vagueness, I promise I'll grab as much info as possible
> upon next encounter of such a thing. As I remember it, it's mainly a matter
> of the module getting suck somehow (and attempts to unload it getting stuck as
> well) and the card not being detected upon subsequent insertions anymore.
I posted a few patches two hours ago. you should check out
"[PATCH] carl9170: fix hung workqueue", because it may be fixes the bug.
> I just tried the whole setup with the latest wireless-testing sources and your
> patch on the firmware. So far, so good, the problems I had previously are not
> showing up. I'm now just adapting your proposition to support rollover and
> conversion of the measurement to nanoseconds.
Rollover checks? Can you please tell me where you exactly see a potential rollover
problem in the proposal?
> One last question about your patch. If a frame transmission fails altogether,
> i.e. the maximum attempts have been made and no ACK has been received
> whatsoever, will the driver get a tx_status with the overall timer spent
> serving that frame anyway (read: that's what I actually want)?
Currently not, but this can be achieved by moving the tsfl = get_clock_counter();
from __wlan_tx to _wlan_tx() and kill the one in wlan_tx_status.
Regards,
Christian
Hello,
On Monday 27 September 2010 15:29:57 Ignacy Gawedzki wrote:
> It's been now some time since I started hacking on drivers for the AR9170
> chipset based cards. I initially wanted to enable wireless link capacity
> estimation (in terms of attainable throughput), based on the measurement of
> data frame service time. In other words, I wanted to measure the time it
> takes the card to fully process each frame it receives from upper layers, from
> the instant it first considers the frame for transmission until the instant
> when the frame is considered processed (reception of ACK for unicast or end of
> transmission for multicast).
Sounds familiar, David H. Lynch Jr. <[email protected]> wanted to do the same,
on the same hardware with same software kit. But as far as I know he abandoned
the project because the hardware does support the RT interrupts he was
hoping for.
> What I ended up doing was to modify the carl9170 firmware to enable the card
> itself to do the measurement and report that value back along the TX status.
>
> The most important question is about struct carl9170_tx_status. Is it safe to
> simply add a u32 duration field and update the CARL9170_TX_STATUS_SIZE to 6?
sure, I've just tested (on top of 1.8.8.2)
---
diff --git a/include/shared/fwcmd.h b/include/shared/fwcmd.h
index d4a4e1d..d7caa33 100644
--- a/include/shared/fwcmd.h
+++ b/include/shared/fwcmd.h
@@ -215,6 +215,8 @@ struct carl9170_tx_status {
u8 rix:2;
u8 tries:3;
u8 success:1;
+
+ u32 test;
} __packed;
struct _carl9170_tx_status {
/*
@@ -223,8 +225,10 @@ struct _carl9170_tx_status {
u8 cookie;
u8 info;
+
+ u32 test;
} __packed;
-#define CARL9170_TX_STATUS_SIZE 2
+#define CARL9170_TX_STATUS_SIZE 6
#define CARL9170_RSP_TX_STATUS_NUM (CARL9170_MAX_CMD_PAYLOAD_LEN / \
sizeof(struct _carl9170_tx_status))
---
without any problems. The device was able to connect and send a few gigs.
Maybe you should be a bit more "precise" about your changes ;).
> After quite some testing, it appears that as soon as I change the size of that
> struct, I start getting things like this (on any recent kernel with recent
> driver+firmware):
>
> usb 1-1: no command feedback received (-110).
> carl9170 cmd: 08 01 00 00 f0 36 1c 00 00 24 00 00 .....6...$..
> usb 1-1: restart device (6)
> ieee80211 phy0: writing reg 0x1c36f0 (val 0x2400) failed (-110)
> usb 1-1: device restarted successfully.
too bad. The firmware obviously crashed but without any hints to
why...
> ------------[ cut here ]------------
> WARNING: at /build/buildd/linux-2.6.35/kernel/workqueue.c:495 flush_cpu_workqueue+0x7a/0x80()
> ...
> Modules linked in: carl9170 mac80211 led_class ath cfg80211 compat ...
> Call Trace:
> [<c014a812>] warn_slowpath_common+0x72/0xa0
> [<c016199a>] ? flush_cpu_workqueue+0x7a/0x80
> [<c016199a>] ? flush_cpu_workqueue+0x7a/0x80
> [<c014a862>] warn_slowpath_null+0x22/0x30
> [<c016199a>] flush_cpu_workqueue+0x7a/0x80
> [<c01620ee>] flush_workqueue+0x3e/0x60
> [<db90f699>] ieee80211_restart_hw+0x19/0x80 [mac80211]
> [<db872d92>] carl9170_restart_work+0xc2/0x150 [carl9170]
> [<c016155e>] run_workqueue+0x8e/0x150
> [<db872cd0>] ? carl9170_restart_work+0x0/0x150 [carl9170]
> [<c01616a4>] worker_thread+0x84/0xe0
> [<c0165920>] ? autoremove_wake_function+0x0/0x50
> [<c0161620>] ? worker_thread+0x0/0xe0
> [<c01654f4>] kthread+0x74/0x80
> [<c0165480>] ? kthread+0x0/0x80
> [<c010363e>] kernel_thread_helper+0x6/0x10
> --[ end trace 163c2ca4bc44c139 ]---
>
> At first glance, it seems to be the result of a reentrant call of
> flush_workqueue.
Wait, wait wait 2.6.35? Every kernel before 2.6.35.2 (and a few other
-stable release) have a serious threading-bug in the usb subsystem.
I strongly recommend that you update your code-base to the
latest wireless-testing.
(Haven't seen the WARN before, kernel/workqueue.c code has changed a lot
and flush_cpu_workqueue is no more...)
Best regards,
Christian
On Tue, Sep 28, 2010 at 01:39:43AM +0200, thus spake Christian Lamparter:
> > I now wonder how that could possibly be due to my modifications in the driver
> > and mac80211 (in a nutshell: retrieve the measurement per frame from the FW
> > and collect it into a stats structure in the sta descriptor, which is later
> > retrieved from userspace through netlink). I'll try without these and report
> > back if that still happens.
> hm, you could also add a "custom" RADIO_TAP field. This way you could use
> wireshark to monitor the round trip times for each individual frame
> (this way you could also export the frames' duration + tx vectors too)
The thing is, I need to measure that during normal operation, when the card is
not in monitor mode. At some point (in fact I was then experimenting with
mini-PCI cards running madwifi), I tried to run a monitor in parallel on
another virtual interface. This turned out not to be working quite right,
because the monitor mode was having an impact on the normal operation of the
regular virtual interface. Besides, sniffing each packet in userspace just to
retrieve my stats seems a bit overkill. I don't really need to collect the
service time measurement for each frame independently, but simply to perform
some kind of accounting.
More precisely, I consider frames according to their length, up to 200 bytes,
from 200 to 400, from 400 to 600, ... and so on, up to the maximum frame size,
in 200 bytes intervals. For each interval, I count the number of frames
transmitted, the cumulated number of bytes and the cumulated service time (all
these numbers are of course maintained *per destination address*). The
userspace process then retrieves these stats for each interval, which
automatically resets all these values to zero, and computes an approximate
function of average throughput vs. frame length. This average throughput
being the cumulated bytes over the cumulated service time, it is a maximum
attainable throughput and not the actual throughput.
Regards,
Ignacy
--
I drive way too fast to worry about cholesterol.
On Tue, Sep 28, 2010 at 01:28:22AM +0200, thus spake Christian Lamparter:
> On Tuesday 28 September 2010 01:01:37 Ignacy Gawedzki wrote:
> > On Mon, Sep 27, 2010 at 07:36:21PM +0200, thus spake Christian Lamparter:
> > > Sure, but why when you have a monotonic 40 MHz timer?
> >
> > Glad to know there is such a thing, then. =)
> or was it 80Mhz? Nevermind, the docs are not very specific.
AFAICT there's a constant in timer.h :
#define AR9170_TICKS_PER_MICROSECOND 80
but there's also that clock_set() function that seems to be setting the clock
up with different frequencies, but I supppose that's a different thing.
> > Okay, I thought these API versions were there to be checked by the driver
> > somehow for conformance.
>
> They are... But only at the "highest" level ;)
> Anyway, there's a bitfield which describe what commands, operation modes
> and features are support by the firmware image.
Very well then. =)
> I posted a few patches two hours ago. you should check out
> "[PATCH] carl9170: fix hung workqueue", because it may be fixes the bug.
I'll give it a try as soon as possible, thanks.
> > I just tried the whole setup with the latest wireless-testing sources and your
> > patch on the firmware. So far, so good, the problems I had previously are not
> > showing up. I'm now just adapting your proposition to support rollover and
> > conversion of the measurement to nanoseconds.
> Rollover checks? Can you please tell me where you exactly see a potential
> rollover problem in the proposal?
Well, what I meant was to support the case when the clock ticks counter wraps
around. Supposing there are 40e6 ticks per second, 2^32 ticks run out in less
than 108 seconds, or maybe I'm missing something here. I then need to
consider the case where comp_tsf ends up not being larger than tsfl. Since
we're dealing with unsigned ints, in this case the simple difference would
end up being something rather large. :/
> > One last question about your patch. If a frame transmission fails altogether,
> > i.e. the maximum attempts have been made and no ACK has been received
> > whatsoever, will the driver get a tx_status with the overall timer spent
> > serving that frame anyway (read: that's what I actually want)?
> Currently not, but this can be achieved by moving the tsfl =
> get_clock_counter(); from __wlan_tx to _wlan_tx() and kill the one in
> wlan_tx_status.
Thanks for that hint, too. =)
Best regards,
Ignacy
--
P.S. All information contained in the above letter is false,
for reasons of military security.