linuxptp-devel

[Linuxptp-devel] Debugging ptp4l

[Drasko D. <dra...@gm...>]

Hi all,
I cross-compiled and tried ptp4l on Pandaboard.

I am getting forllorwing output :

root@airport:/linux-ptp# ./ptp4l -S -i wlan0 -m
ptp4l[106746.946]: port 1: get_ts_info not supported
ptp4l[106746.950]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[106746.951]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[106752.950]: port 1: LISTENING to MASTER on
ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
ptp4l[106753.952]: poll tx timestamp failed: Success
ptp4l[106753.952]: port 1: send sync failed
ptp4l[106753.952]: port 1: MASTER to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
ptp4l[106769.956]: port 1: FAULTY to LISTENING on FAULT_CLEARED
ptp4l[106775.956]: port 1: LISTENING to MASTER on
ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
ptp4l[106776.958]: poll tx timestamp failed: Success
ptp4l[106776.958]: port 1: send sync failed
ptp4l[106776.958]: port 1: MASTER to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
ptp4l[106792.963]: port 1: FAULTY to LISTENING on FAULT_CLEARED
ptp4l[106798.963]: port 1: LISTENING to MASTER on
ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES
ptp4l[106799.964]: poll tx timestamp failed: Success
ptp4l[106799.964]: port 1: send sync failed

What is happening here and how to debug this ?

Best regards,
Drasko

Re: [Linuxptp-devel] Debugging ptp4l

[Richard C. <ric...@gm...>]

On Thu, May 30, 2013 at 03:36:17PM +0200, Drasko DRASKOVIC wrote:

> ptp4l[106799.964]: poll tx timestamp failed: Success
> ptp4l[106799.964]: port 1: send sync failed
> 
> What is happening here and how to debug this ?

Your MAC driver is lacking transmit time stamp support. I don't know
what the pandaboard has (davinci_emac?), but you would need to add a
call to

 * skb_tx_timestamp() - Driver hook for transmit timestamping
 *
 * Ethernet MAC Drivers should call this function in their hard_xmit()
 * function immediately before giving the sk_buff to the MAC hardware.

in your MAC driver.

HTH,
Richard

Re: [Linuxptp-devel] Debugging ptp4l

[Drasko D. <dra...@gm...>]

Hi Richard,

On Thu, May 30, 2013 at 4:41 PM, Richard Cochran
<ric...@gm...> wrote:
> On Thu, May 30, 2013 at 03:36:17PM +0200, Drasko DRASKOVIC wrote:
>
>> ptp4l[106799.964]: poll tx timestamp failed: Success
>> ptp4l[106799.964]: port 1: send sync failed
>>
>> What is happening here and how to debug this ?
>
> Your MAC driver is lacking transmit time stamp support. I don't know
> what the pandaboard has (davinci_emac?), but you would need to add a
> call to
>
>  * skb_tx_timestamp() - Driver hook for transmit timestamping
>  *
>  * Ethernet MAC Drivers should call this function in their hard_xmit()
>  * function immediately before giving the sk_buff to the MAC hardware.
>
> in your MAC driver.

Thanks for this information and for your help.
I was suspecting that this is the source of error, as it has been
discussed earlier on this list, but error :
port 1: MASTER to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
is difficult to understand,

By the way, what are port 0 and port 1?

I will grep for some examples, to see how it is currently done in the kernel.

Is there any example for wlan drivers that I can take - what would be
the most quick and dirty way, just to have all tools in place. I will
work later on precision, for now I just want something that compiles
and that make server and client communicate (even if the timestamps
are imprecise).

Best regards,
Drasko

Re: [Linuxptp-devel] Debugging ptp4l

[Libor P. <lpe...@su...>]

Drasko,

On Thu 30-05-13 17:03:21, Drasko DRASKOVIC wrote:
[...]
> I was suspecting that this is the source of error, as it has been
> discussed earlier on this list, but error :
> port 1: MASTER to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
> is difficult to understand,

I believe commit 7ce1486 (fix the check for supported timestamping modes)
addresses difficult diagnostics in this situation.  ptp4l with the fix should
stop during initialization with an error message when underlying NIC driver
does not support the required time stamping mode.

HTH,
	Libor

Re: [Linuxptp-devel] Debugging ptp4l

[Richard C. <ric...@gm...>]

On Thu, May 30, 2013 at 05:03:21PM +0200, Drasko DRASKOVIC wrote:
> 
> By the way, what are port 0 and port 1?

Port 0 in an internal management port (over UDP).

Port 1 is the first physical port.
 
HTH,
Richard

Re: [Linuxptp-devel] Debugging ptp4l

[Richard C. <ric...@gm...>]

On Thu, May 30, 2013 at 05:03:21PM +0200, Drasko DRASKOVIC wrote:
> 
> I will grep for some examples, to see how it is currently done in the kernel.

If tell me your MAC driver, I can suggest a likely place to call the
tx time stamp function.

Thanks,
Richard

Re: [Linuxptp-devel] Debugging ptp4l

[Drasko D. <dra...@gm...>]

On Thu, May 30, 2013 at 5:59 PM, Richard Cochran
<ric...@gm...> wrote:
> On Thu, May 30, 2013 at 05:03:21PM +0200, Drasko DRASKOVIC wrote:
>>
>> I will grep for some examples, to see how it is currently done in the kernel.
>
> If tell me your MAC driver, I can suggest a likely place to call the
> tx time stamp function.

Hello Richard,
Pandaboard uses this WiFi driver :
https://github.com/garwedgess/ti-wlan/tree/master/compat-wireless-wl12xx/drivers/net/wireless/wl12xx

I put skb_tx_timestamp(skb); inside of wl1271_prepare_tx_frame() here
: https://github.com/garwedgess/ti-wlan/blob/master/compat-wireless-wl12xx/drivers/net/wireless/wl12xx/tx.c#L443.

It compiled, but I was unable to insert the module afterwards :

root@panda:~# modprobe wl12xx
FATAL: Error inserting wl12xx
(/lib/modules/3.2.40-dirty/kernel/drivers/net/wireless/wl12xx/wl12xx.ko):
Unknown symbol in module, or unknown parameter (see dmesg)
root@panda:~# dmesg
...
[   77.510345] wl12xx: Unknown symbol skb_clone_tx_timestamp (err 0)
...


Best regards,
Drasko

Re: [Linuxptp-devel] Debugging ptp4l

[Drasko D. <dra...@gm...>]

On Thu, May 30, 2013 at 6:59 PM, Drasko DRASKOVIC
<dra...@gm...> wrote:
> On Thu, May 30, 2013 at 5:59 PM, Richard Cochran
> <ric...@gm...> wrote:
>> On Thu, May 30, 2013 at 05:03:21PM +0200, Drasko DRASKOVIC wrote:
>>>
>>> I will grep for some examples, to see how it is currently done in the kernel.
>>
>> If tell me your MAC driver, I can suggest a likely place to call the
>> tx time stamp function.
>
> Hello Richard,
> Pandaboard uses this WiFi driver :
> https://github.com/garwedgess/ti-wlan/tree/master/compat-wireless-wl12xx/drivers/net/wireless/wl12xx
>
> I put skb_tx_timestamp(skb); inside of wl1271_prepare_tx_frame() here
> : https://github.com/garwedgess/ti-wlan/blob/master/compat-wireless-wl12xx/drivers/net/wireless/wl12xx/tx.c#L443.
>
> It compiled, but I was unable to insert the module afterwards :
>
> root@panda:~# modprobe wl12xx
> FATAL: Error inserting wl12xx
> (/lib/modules/3.2.40-dirty/kernel/drivers/net/wireless/wl12xx/wl12xx.ko):
> Unknown symbol in module, or unknown parameter (see dmesg)
> root@panda:~# dmesg
> ...
> [   77.510345] wl12xx: Unknown symbol skb_clone_tx_timestamp (err 0)
> ...

Sorry, seems like I did not take correct uImage that corresponds new
module. I did now, and module was loaded fine.

Anyway, do you thing that the place (file and function) I inserted
skb_tx_timestamp(skb); is a good candidate ?

Best regards,
Drasko

Re: [Linuxptp-devel] Debugging ptp4l

[Richard C. <ric...@gm...>]

On Thu, May 30, 2013 at 07:05:41PM +0200, Drasko DRASKOVIC wrote:
> 
> Anyway, do you thing that the place (file and function) I inserted
> skb_tx_timestamp(skb); is a good candidate ?

Drasko, you are jumping from using a wired lan to wireless. My
suggestion about adding skb_tx_timestamp was about enabling your
Ethernet MAC driver.

I can't really say anything about running PTP over 802.11 without
looking into the whole issue first, and right now I haven't time for
that.

Sorry,
Richard

Re: [Linuxptp-devel] Debugging ptp4l

[Richard C. <ric...@gm...>]

On Thu, May 30, 2013 at 05:57:44PM +0200, Richard Cochran wrote:
> On Thu, May 30, 2013 at 05:03:21PM +0200, Drasko DRASKOVIC wrote:
> > 
> > By the way, what are port 0 and port 1?
> 
> Port 0 in an internal management port (over UDP).

Oops, I meant UDS (UNIX Domain Socket).

Richard

Re: [Linuxptp-devel] Debugging ptp4l

[Drasko D. <dra...@gm...>]

On Thu, May 30, 2013 at 7:30 PM, Richard Cochran
<ric...@gm...> wrote:
> On Thu, May 30, 2013 at 05:57:44PM +0200, Richard Cochran wrote:
>> On Thu, May 30, 2013 at 05:03:21PM +0200, Drasko DRASKOVIC wrote:
>> >
>> > By the way, what are port 0 and port 1?
>>
>> Port 0 in an internal management port (over UDP).
>
> Oops, I meant UDS (UNIX Domain Socket).
>
> Richard

What I am seeing now, after inserting skb_tx_timestamp(skb)  as I
explained before :

Master side :
root@master:/linux-ptp# ./ptp4l -S -i wlan0 -m
ptp4l[1591.227]: port 1: get_ts_info not supported
ptp4l[1591.237]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[1591.237]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[1597.237]: port 1: LISTENING to MASTER on ANNOUNCE_RECEIPT_TIMEOUT_EXPIRES

This seems OK.

But on the slave side :
root@slave:/linux-ptp# ./ptp4l -S -i wlan0 -s -m
ptp4l[228.367]: port 1: get_ts_info not supported
ptp4l[228.371]: port 1: INITIALIZING to LISTENING on INITIALIZE
ptp4l[228.372]: port 0: INITIALIZING to LISTENING on INITIALIZE
ptp4l[229.013]: port 1: new foreign master deadbe.fffe.ef0000-1
ptp4l[232.902]: selected best master clock deadbe.fffe.ef0000
ptp4l[232.902]: foreign master not using PTP timescale
ptp4l[232.902]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[234.056]: poll tx timestamp failed: No such file or directory
ptp4l[234.056]: port 1: send delay request failed
ptp4l[234.056]: port 1: UNCALIBRATED to FAULTY on FAULT_DETECTED
(FT_UNSPECIFIED)
ptp4l[250.060]: port 1: FAULTY to LISTENING on FAULT_CLEARED
ptp4l[250.923]: port 1: new foreign master deadbe.fffe.ef0000-1
ptp4l[255.019]: selected best master clock deadbe.fffe.ef0000
ptp4l[255.019]: foreign master not using PTP timescale
ptp4l[255.019]: port 1: LISTENING to UNCALIBRATED on RS_SLAVE
ptp4l[255.443]: poll tx timestamp failed: No such file or directory
ptp4l[255.443]: port 1: send delay request failed
ptp4l[255.444]: port 1: UNCALIBRATED to FAULTY on FAULT_DETECTED
(FT_UNSPECIFIED)




What is :
ptp4l[234.056]: poll tx timestamp failed: No such file or directory
ptp4l[234.056]: port 1: send delay request failed


and how is it different than :
ptp4l[106753.952]: poll tx timestamp failed: Success
ptp4l[106753.952]: port 1: send sync failed
ptp4l[106753.952]: port 1: MASTER to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)

that I was seeing on MASTER side before skb_tx_timestamp(skb) was
inserted in the driver ?

Best regards,
Drasko

Re: [Linuxptp-devel] Debugging ptp4l

[Libor P. <lpe...@su...>]

On Thu 30-05-13 19:34:45, Drasko DRASKOVIC wrote:
> What is :
> ptp4l[234.056]: poll tx timestamp failed: No such file or directory
                          
The above is partly garbage.  Please apply 7b02a5e (fix misleading pr_err on
poll timeout) to your sources.

> ptp4l[234.056]: port 1: send delay request failed

That merely means that message could not be sent due to the missing time
stamping capability.

> and how is it different than :
> ptp4l[106753.952]: poll tx timestamp failed: Success
> ptp4l[106753.952]: port 1: send sync failed

It's the same situation at different place in the code, just the error message
is different.  Perhaps more intuitive messages are worth inventing.

> ptp4l[106753.952]: port 1: MASTER to FAULTY on FAULT_DETECTED (FT_UNSPECIFIED)
> 
> that I was seeing on MASTER side before skb_tx_timestamp(skb) was
> inserted in the driver ?

As to my understanding also the receiving needs time stamping in the driver.

Please update to the latest linuxptp development version before proceeding with
your testing.

Libor