Thread: [Linuxptp-users] asCapable and FD_MANNO_TIMER questions
PTP IEEE 1588 stack for Linux
Brought to you by:
rcochran
Menu
▾
▴
linuxptp-users
|
From: Drasko D. <dra...@gm...> - 2013-05-31 12:31:34
|
Hi all, I tried to add some logs for debugging. on master side I have following : root@master:/linux-ptp# ./ptp4l -S -i wlan0 -m -l9 ptp4l[62586.626]: port 1: get_ts_info not supported ptp4l[62586.630]: port 1: INITIALIZING to LISTENING on INITIALIZE ptp4l[62586.630]: port 0: INITIALIZING to LISTENING on INITIALIZE ptp4l[62592.630]: port 1: announce timeout ptp4l[62592.630]: port 1: LISTENING to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES ptp4l[62593.630]: port 1: master sync timeout ptp4l[62593.630]: port 1: setting asCapable ptp4l[62594.630]: port 1: master tx announce timeout ptp4l[62594.631]: port 1: master sync timeout ptp4l[62595.631]: port 1: master sync timeout ptp4l[62596.631]: port 1: master tx announce timeout ptp4l[62596.631]: port 1: master sync timeout ptp4l[62597.631]: port 1: master sync timeout At this point I am wondering : 1) What is does exactly exectly asCapable flasg represent? 2) I can see that tx announce timeouts because of FD_MANNO_TIMER event in FSM. Any ideas why this is happening and where to look? Best regards, Drasko |
|
From: Richard C. <ric...@gm...> - 2013-05-31 14:09:57
|
On Fri, May 31, 2013 at 02:31:27PM +0200, Drasko DRASKOVIC wrote: > 1) What is does exactly exectly asCapable flasg represent? This is explained in 802.1AS. > 2) I can see that tx announce timeouts because of FD_MANNO_TIMER event > in FSM. Any ideas why this is happening and where to look? This is the master's announce timer. It means that it is time to transmit an announce message. HTH, Richard |
|
From: Drasko D. <dra...@gm...> - 2013-05-31 15:32:37
|
On Fri, May 31, 2013 at 4:09 PM, Richard Cochran
<ric...@gm...> wrote:
> On Fri, May 31, 2013 at 02:31:27PM +0200, Drasko DRASKOVIC wrote:
>
>> 1) What is does exactly exectly asCapable flasg represent?
>
> This is explained in 802.1AS.
Yes, found it. Based on what I can read here, this log is a good sign.
>> 2) I can see that tx announce timeouts because of FD_MANNO_TIMER event
>> in FSM. Any ideas why this is happening and where to look?
>
> This is the master's announce timer. It means that it is time to
> transmit an announce message.
Great, then this is also a good sign. From what I can see in the code,
port_tx_announce() is called.
>From log presented in previous mail I can now conclude that master
keeps broadcasting "announce" and "sync" messages.
Can somebody please confirm that this is normal behavior, and that
these log actually does not represent any error (abnormal state) on
master side?
On the slave side, I have an evident error :
root@slave:~/linuxptp# ./ptp4l -S -i wlan0 -m -l9 -s
ptp4l[7264.414]: port 1: get_ts_info not supported
ptp4l[7264.424]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[7264.425]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[7264.772]: port 1: setting asCapable
ptp4l[7264.773]: port 1: new foreign master deadbe.fffe.ef0000-1
ptp4l[7270.424]: port 1: announce timeout
ptp4l[7270.711]: selected best master clock deadbe.fffe.ef0000
ptp4l[7270.711]: foreign master not using PTP timescale
ptp4l[7270.711]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[7271.892]: port 1: delay timeout
ptp4l[7271.894]: poll tx timestamp failed: Success
ptp4l[7271.894]: port 1: send delay request failed
ptp4l[7271.894]: port 1: UNCALIBRATED to FAULTY on FAULT_DETECTED
(FT_UNSPECIFIED)
ptp4l[7271.896]: waiting 2^{4} seconds to clear fault on port 0
Is there any hints how this delay failure should be examined ? Looking
at this code in port_delay_request() :
cnt = transport_send(p->trp, &p->fda, 1, msg, pdulen, &msg->hwts);
if (cnt <= 0) {
pr_err("port %hu: send delay request failed", portnum(p));
goto out;
}
it does not give too much information why sending this message fails.
Secondly, I am seeing again "poll tx timestamp failed: Success",
although I have added skb_tx_timestamp(skb); to the wireless driver.
This seemd to work well on master side, so master stopped complain. I
am not sure why on the slave side I am facing the same error, while
using the same driver with tx_timestamp added.
Best regards,
Drasko
|
|
From: Keller, J. E <jac...@in...> - 2013-05-31 19:59:31
|
> -----Original Message-----
> From: Drasko DRASKOVIC [mailto:dra...@gm...]
> Sent: Friday, May 31, 2013 8:32 AM
> To: Richard Cochran
> Cc: lin...@li...
> Subject: Re: [Linuxptp-users] asCapable and FD_MANNO_TIMER
> questions
>
> On Fri, May 31, 2013 at 4:09 PM, Richard Cochran
> <ric...@gm...> wrote:
> > On Fri, May 31, 2013 at 02:31:27PM +0200, Drasko DRASKOVIC wrote:
> >
> >> 1) What is does exactly exectly asCapable flasg represent?
> >
> > This is explained in 802.1AS.
>
> Yes, found it. Based on what I can read here, this log is a good sign.
>
> >> 2) I can see that tx announce timeouts because of FD_MANNO_TIMER
> event
> >> in FSM. Any ideas why this is happening and where to look?
> >
> > This is the master's announce timer. It means that it is time to
> > transmit an announce message.
>
> Great, then this is also a good sign. From what I can see in the code,
> port_tx_announce() is called.
>
> >From log presented in previous mail I can now conclude that master
> keeps broadcasting "announce" and "sync" messages.
>
> Can somebody please confirm that this is normal behavior, and that
> these log actually does not represent any error (abnormal state) on
> master side?
>
>
> On the slave side, I have an evident error :
>
> root@slave:~/linuxptp# ./ptp4l -S -i wlan0 -m -l9 -s
> ptp4l[7264.414]: port 1: get_ts_info not supported
> ptp4l[7264.424]: port 1: INITIALIZING to LISTENING on INITIALIZE
> ptp4l[7264.425]: port 0: INITIALIZING to LISTENING on INITIALIZE
> ptp4l[7264.772]: port 1: setting asCapable
> ptp4l[7264.773]: port 1: new foreign master deadbe.fffe.ef0000-1
> ptp4l[7270.424]: port 1: announce timeout
> ptp4l[7270.711]: selected best master clock deadbe.fffe.ef0000
> ptp4l[7270.711]: foreign master not using PTP timescale
> ptp4l[7270.711]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
> ptp4l[7271.892]: port 1: delay timeout
> ptp4l[7271.894]: poll tx timestamp failed: Success
> ptp4l[7271.894]: port 1: send delay request failed
> ptp4l[7271.894]: port 1: UNCALIBRATED to FAULTY on FAULT_DETECTED
> (FT_UNSPECIFIED)
> ptp4l[7271.896]: waiting 2^{4} seconds to clear fault on port 0
>
> Is there any hints how this delay failure should be examined ? Looking
> at this code in port_delay_request() :
> cnt = transport_send(p->trp, &p->fda, 1, msg, pdulen, &msg->hwts);
> if (cnt <= 0) {
> pr_err("port %hu: send delay request failed",
> portnum(p));
> goto out;
> }
> it does not give too much information why sending this message fails.
>
> Secondly, I am seeing again "poll tx timestamp failed: Success",
> although I have added skb_tx_timestamp(skb); to the wireless driver.
> This seemd to work well on master side, so master stopped complain. I
> am not sure why on the slave side I am facing the same error, while
> using the same driver with tx_timestamp added.
>
> Best regards,
> Drasko
>
Are you certain that you are using the same driver? The error you are seeing here is due to poll timing out. The misleading error message has been fixed in the upstream git repository but I don't believe it has been released yet.
That means that the tx timestamp isn't being returned within the timelimit meaning your driver is not actually getting the timestamp result.
- Jake
|
|
From: Drasko D. <dra...@gm...> - 2013-05-31 21:10:22
|
Hi Jake, On Fri, May 31, 2013 at 9:59 PM, Keller, Jacob E <jac...@in...> wrote: > Are you certain that you are using the same driver? Yes, I am pretty sure of this, because I am using my modified driver with bunch of printouts for debug. > The error you are seeing here is due to poll timing out. I can see that poll hits the sk_tx_timeout TO in sk_receive(). I am as well suspecting on the way wireless stack works in Linux. >The misleading error message has been fixed in the upstream git repository but I don't believe it has been released yet. This is not such a problem, code is really well written and easy to read. I can figure out what is happening now that I have starting to be a little familiar ;). > That means that the tx timestamp isn't being returned within the timelimit meaning your driver is not actually getting the timestamp result. Exactly. Now that I understood methodolgy of timestamp passing within socket error queue (as explained here http://www.cs.fsu.edu/~baker/devices/lxr/http/source/linux/Documentation/networking/timestamping.txt), I started tracing what happens on packet TX in the driver through here : http://lxr.free-electrons.com/source/net/core/skbuff.c?v=3.0#L3007 and here: http://lxr.free-electrons.com/source/net/core/skbuff.c?v=3.0#L2986, and these functions seem to work fine (at least none returns with an error). I have spotted one strange thing though - when I put my device in AP mode, I have logs like this : root@master:/linux-ptp# ./ptp4l -S -i wlan0 -m -l9 ptp4l[62586.626]: port 1: get_ts_info not supported ptp4l[62586.630]: port 1: INITIALIZING to LISTENING on INITIALIZE ptp4l[62586.630]: port 0: INITIALIZING to LISTENING on INITIALIZE ptp4l[62592.630]: port 1: announce timeout ptp4l[62592.630]: port 1: LISTENING to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES ptp4l[62593.630]: port 1: master sync timeout ptp4l[62593.630]: port 1: setting asCapable ptp4l[62594.630]: port 1: master tx announce timeout ptp4l[62594.631]: port 1: master sync timeout ptp4l[62595.631]: port 1: master sync timeout ptp4l[62596.631]: port 1: master tx announce timeout ptp4l[62596.631]: port 1: master sync timeout ptp4l[62597.631]: port 1: master sync timeout ... which is rather good news, and means that TX timestamping works fine an ptp4l master started broadcasting anounce and sync messages. However, when I put my wireless device in STA mode, I am getting logs like this : root@slave:~/linuxptp# ./ptp4l -S -i wlan0 -m -l9 -s ptp4l[7264.414]: port 1: get_ts_info not supported ptp4l[7264.424]: port 1: INITIALIZING to LISTENING on INITIALIZE ptp4l[7264.425]: port 0: INITIALIZING to LISTENING on INITIALIZE ptp4l[7264.772]: port 1: setting asCapable ptp4l[7264.773]: port 1: new foreign master deadbe.fffe.ef0000-1 ptp4l[7270.424]: port 1: announce timeout ptp4l[7270.711]: selected best master clock deadbe.fffe.ef0000 ptp4l[7270.711]: foreign master not using PTP timescale ptp4l[7270.711]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE ptp4l[7271.892]: port 1: delay timeout ptp4l[7271.894]: poll tx timestamp failed: Success ptp4l[7271.894]: port 1: send delay request failed ptp4l[7271.894]: port 1: UNCALIBRATED to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED) ptp4l[7271.896]: waiting 2^{4} seconds to clear fault on port 0 which would say that TX timestamping for some reason do not work (although same driver is used). In STA mode I can still see that kernel's skb_tstamp_tx() function is adequately called, as I explained earlier, and from my log I would say that I inserted skb_tx_timestamp() in the correct place (actually, I have put it here : https://github.com/garwedgess/ti-wlan/blob/master/compat-wireless-wl12xx/drivers/net/wireless/wl12xx/main.c#L1563, which seems to be driver's TX function). I will have to analyze what differences for wrror queue driver makes when in AP and when in STA mode. But at this point I would like to be sure that it is error queue problem, and I still have not found where to look for error type ENOENT that Richard was talking about, in order to confirm that it is error queue problem or something else. Does anybody knows how I can check this (to confirm that wireless stack returns ENOENT)? BR, Drasko |
|
From: Keller, J. E <jac...@in...> - 2013-05-31 21:14:55
|
> -----Original Message----- > From: Drasko DRASKOVIC [mailto:dra...@gm...] > Sent: Friday, May 31, 2013 2:10 PM > To: Keller, Jacob E > Cc: Richard Cochran; lin...@li... > Subject: Re: [Linuxptp-users] asCapable and FD_MANNO_TIMER > questions > > Hi Jake, Hi Drasko, > > On Fri, May 31, 2013 at 9:59 PM, Keller, Jacob E > <jac...@in...> wrote: > > Are you certain that you are using the same driver? > Yes, I am pretty sure of this, because I am using my modified driver > with bunch of printouts for debug. > > > The error you are seeing here is due to poll timing out. > I can see that poll hits the sk_tx_timeout TO in sk_receive(). I am as > well suspecting on the way wireless stack works in Linux. > > >The misleading error message has been fixed in the upstream git > repository but I don't believe it has been released yet. > This is not such a problem, code is really well written and easy to > read. I can figure out what is happening now that I have starting to > be a little familiar ;). > > > That means that the tx timestamp isn't being returned within the > timelimit meaning your driver is not actually getting the timestamp > result. > Exactly. Now that I understood methodolgy of timestamp passing within > socket error queue (as explained here > http://www.cs.fsu.edu/~baker/devices/lxr/http/source/linux/Docume > ntation/networking/timestamping.txt), > I started tracing what happens on packet TX in the driver through here > : http://lxr.free-electrons.com/source/net/core/skbuff.c?v=3.0#L3007 > and here: http://lxr.free- > electrons.com/source/net/core/skbuff.c?v=3.0#L2986, > and these functions seem to work fine (at least none returns with an > error). > > I have spotted one strange thing though - when I put my device in AP > mode, I have logs like this : > root@master:/linux-ptp# ./ptp4l -S -i wlan0 -m -l9 > ptp4l[62586.626]: port 1: get_ts_info not supported > ptp4l[62586.630]: port 1: INITIALIZING to LISTENING on INITIALIZE > ptp4l[62586.630]: port 0: INITIALIZING to LISTENING on INITIALIZE > ptp4l[62592.630]: port 1: announce timeout > ptp4l[62592.630]: port 1: LISTENING to MASTER on > ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES > ptp4l[62593.630]: port 1: master sync timeout > ptp4l[62593.630]: port 1: setting asCapable > ptp4l[62594.630]: port 1: master tx announce timeout > ptp4l[62594.631]: port 1: master sync timeout > ptp4l[62595.631]: port 1: master sync timeout > ptp4l[62596.631]: port 1: master tx announce timeout > ptp4l[62596.631]: port 1: master sync timeout > ptp4l[62597.631]: port 1: master sync timeout > ... > > which is rather good news, and means that TX timestamping works fine > an ptp4l master started broadcasting anounce and sync messages. > > However, when I put my wireless device in STA mode, I am getting logs > like this : > root@slave:~/linuxptp# ./ptp4l -S -i wlan0 -m -l9 -s > ptp4l[7264.414]: port 1: get_ts_info not supported > ptp4l[7264.424]: port 1: INITIALIZING to LISTENING on INITIALIZE > ptp4l[7264.425]: port 0: INITIALIZING to LISTENING on INITIALIZE > ptp4l[7264.772]: port 1: setting asCapable > ptp4l[7264.773]: port 1: new foreign master deadbe.fffe.ef0000-1 > ptp4l[7270.424]: port 1: announce timeout > ptp4l[7270.711]: selected best master clock deadbe.fffe.ef0000 > ptp4l[7270.711]: foreign master not using PTP timescale > ptp4l[7270.711]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE > ptp4l[7271.892]: port 1: delay timeout > ptp4l[7271.894]: poll tx timestamp failed: Success > ptp4l[7271.894]: port 1: send delay request failed > ptp4l[7271.894]: port 1: UNCALIBRATED to FAULTY on FAULT_DETECTED > (FT_UNSPECIFIED) > ptp4l[7271.896]: waiting 2^{4} seconds to clear fault on port 0 > > which would say that TX timestamping for some reason do not work > (although same driver is used). > > In STA mode I can still see that kernel's skb_tstamp_tx() function is > adequately called, as I explained earlier, and from my log I would say > that I inserted skb_tx_timestamp() in the correct place (actually, I > have put it here : > https://github.com/garwedgess/ti-wlan/blob/master/compat-wireless- > wl12xx/drivers/net/wireless/wl12xx/main.c#L1563, > which seems to be driver's TX function). > It is possibly due to the poll timeout which is set to 1. You could try to increase this. The value is for polling 1 second which it is possible in STA mode it actually takes longer than 1 second to transmit your packet? I am not familiar that much with wireless devices.. But you could attempt to see if setting sk_tx_timeout higher (should be a configuration option) works. > I will have to analyze what differences for wrror queue driver makes > when in AP and when in STA mode. > > But at this point I would like to be sure that it is error queue > problem, and I still have not found where to look for error type > ENOENT that Richard was talking about, in order to confirm that it is > error queue problem or something else. > > Does anybody knows how I can check this (to confirm that wireless > stack returns ENOENT)? I do not know this, but you should be able to go up the polling stack to see where poll is waiting on and see what error you were getting there...? - Jake > > BR, > Drasko |
|
From: Richard C. <ric...@gm...> - 2013-06-01 06:25:25
|
On Fri, May 31, 2013 at 11:10:13PM +0200, Drasko DRASKOVIC wrote: > > I will have to analyze what differences for wrror queue driver makes > when in AP and when in STA mode. You are going to have to spend some time in order to understand the Linux kernel wifi stack. I think no one on this list knows anything about it. I did stumble upon this site today: http://wireless.kernel.org/en/developers/Documentation/mac80211 Good luck, Richard |
×
Want the latest updates on software, tech news, and AI?
Get latest updates about software, tech news, and AI from SourceForge directly in your inbox once a month.
Thanks for helping keep SourceForge clean.
X