Thread: [Linuxptp-users] phc2sys[273995.639]: failed to read clock: Invalid argument
PTP IEEE 1588 stack for Linux
Brought to you by:
rcochran
Menu
▾
▴
linuxptp-users
|
From: Pham, C. <Cal...@ne...> - 2014-03-03 21:19:35
|
Hi all,
I've been trying to run phc2sys but it kept print this message on the screen and the system clock was found not able to sync to /dev/ptp0. My command was: ./phc2sys -w -s /dev/ptp0 -m
phc2sys[273995.639]: failed to read clock: Invalid argument
phc2sys[273996.639]: failed to read clock: Invalid argument
phc2sys[273997.639]: failed to read clock: Invalid argument
phc2sys[273998.639]: failed to read clock: Invalid argument
phc2sys[273999.639]: failed to read clock: Invalid argument
I am running kernel 3.7.5., intel I350 and linuxptp-1.4. I've found that the print messages came from the function call: clock_gettime(clkid, &tsrc) at line 106 in phc2sys.c:
if (clock_gettime(sysclk, &tdst1) ||
clock_gettime(clkid, &tsrc) ||
clock_gettime(sysclk, &tdst2)) {
pr_err("failed to read clock: %m");
return 0;
}
I forced the code to ignore the error by commenting out "return 0", phc2sys seemed to work fine; I mean the system clock was able to sync to /dev/ptp0 fine. Does anyone know why?
Thanks!
Calvin Pham
|
|
From: Richard C. <ric...@gm...> - 2014-03-04 09:26:48
|
On Mon, Mar 03, 2014 at 09:06:37PM +0000, Pham, Calvin wrote:
> I forced the code to ignore the error by commenting out "return 0", phc2sys seemed to work fine; I mean the system clock was able to sync to /dev/ptp0 fine. Does anyone know why?
This sounds like a driver bug. Can you give the output of the
following commands?
uname -a
ethtool -T eth0
testptp -g
Thanks,
Richard
|
|
From: Pham, C. <Cal...@ne...> - 2014-03-04 13:56:05
|
Hi Richard,
Below is the outputs of the commands. The current ethtool version doesn't support -T option so I have to compile version 3.7 and run for the source directory. Thanks for your help!
> the output of uname -a
[root@V4-CALVIN ~]# uname -a
Linux V4-CALVIN 3.7.5 #1 SMP Tue Feb 26 16:40:13 MST 2013 x86_64 x86_64 x86_64 GNU/Linux
> ethtool -T eth0
[root@V4-CALVIN ethtool-3.7]# ./ethtool -T eth0
Time stamping parameters for eth0:
Capabilities:
hardware-transmit (SOF_TIMESTAMPING_TX_HARDWARE)
software-transmit (SOF_TIMESTAMPING_TX_SOFTWARE)
hardware-receive (SOF_TIMESTAMPING_RX_HARDWARE)
software-receive (SOF_TIMESTAMPING_RX_SOFTWARE)
software-system-clock (SOF_TIMESTAMPING_SOFTWARE)
hardware-raw-clock (SOF_TIMESTAMPING_RAW_HARDWARE)
PTP Hardware Clock: 0
Hardware Transmit Timestamp Modes:
off (HWTSTAMP_TX_OFF)
on (HWTSTAMP_TX_ON)
Hardware Receive Filter Modes:
none (HWTSTAMP_FILTER_NONE)
all (HWTSTAMP_FILTER_ALL)
> testptp -g
[root@V4-CALVIN ptp]# ./testptp -g
gettime: CLK_ID 0xffffffe3
clock time: 1393941119.523279956 or Tue Mar 4 08:51:59 2014
clock_gettime %m: Invalid argument
> ethtool -i eth0
[root@V4-CALVIN ptp]# ethtool -i eth0
driver: igb
version: 5.0.6
firmware-version: 1.61, 0x8000090e
bus-info: 0000:08:00.0
supports-statistics: yes
supports-test: yes
supports-eeprom-access: yes
supports-register-dump: yes
-----Original Message-----
From: Richard Cochran [mailto:ric...@gm...]
Sent: Tuesday, March 04, 2014 4:27 AM
To: Pham, Calvin
Cc: lin...@li...
Subject: Re: [Linuxptp-users] phc2sys[273995.639]: failed to read clock: Invalid argument
On Mon, Mar 03, 2014 at 09:06:37PM +0000, Pham, Calvin wrote:
> I forced the code to ignore the error by commenting out "return 0", phc2sys seemed to work fine; I mean the system clock was able to sync to /dev/ptp0 fine. Does anyone know why?
This sounds like a driver bug. Can you give the output of the following commands?
uname -a
ethtool -T eth0
testptp -g
Thanks,
Richard
|
|
From: Richard C. <ric...@gm...> - 2014-03-04 15:18:18
|
On Tue, Mar 04, 2014 at 01:55:56PM +0000, Pham, Calvin wrote: > > > testptp -g > [root@V4-CALVIN ptp]# ./testptp -g > gettime: CLK_ID 0xffffffe3 > clock time: 1393941119.523279956 or Tue Mar 4 08:51:59 2014 > clock_gettime %m: Invalid argument [ It looks like you changed testptp to always print the time. ] I looked at the igb driver, and it always returns 0 for its gettime method. So now this looks more like a glibc bug. Can you run 'testptp -g' under strace and ltrace and post the results? Thanks, Richard |
|
From: Pham, C. <Cal...@ne...> - 2014-03-04 15:49:11
|
Richard,
Calvin> output of strace
strace ./testptp -d /dev/ptp0 -g
execve("./testptp", ["./testptp", "-d", "/dev/ptp0", "-g"], [/* 20 vars */]) = 0
brk(0) = 0x1aa3000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0f8e45d000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=41323, ...}) = 0
mmap(NULL, 41323, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f0f8e452000
close(3) = 0
open("/lib64/librt.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0`\"@\2265\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=48128, ...}) = 0
mmap(0x3596400000, 2128984, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x3596400000
mprotect(0x3596407000, 2093056, PROT_NONE) = 0
mmap(0x3596606000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x6000) = 0x3596606000
close(3) = 0
open("/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\260\27\202\2255\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=2076800, ...}) = 0
mmap(0x3595800000, 3896632, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x3595800000
mprotect(0x35959ad000, 2097152, PROT_NONE) = 0
mmap(0x3595bad000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1ad000) = 0x3595bad000
mmap(0x3595bb3000, 17720, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x3595bb3000
close(3) = 0
open("/lib64/libpthread.so.0", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\320k\0\2265\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=145176, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0f8e451000
mmap(0x3596000000, 2208760, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x3596000000
mprotect(0x3596017000, 2093056, PROT_NONE) = 0
mmap(0x3596216000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x16000) = 0x3596216000
mmap(0x3596218000, 13304, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x3596218000
close(3) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0f8e450000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0f8e44f000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0f8e44e000
arch_prctl(ARCH_SET_FS, 0x7f0f8e44f700) = 0
mprotect(0x3595bad000, 16384, PROT_READ) = 0
mprotect(0x3596216000, 4096, PROT_READ) = 0
mprotect(0x3596606000, 4096, PROT_READ) = 0
mprotect(0x3595621000, 4096, PROT_READ) = 0
munmap(0x7f0f8e452000, 41323) = 0
set_tid_address(0x7f0f8e44f9d0) = 2589
set_robust_list(0x7f0f8e44f9e0, 24) = 0
rt_sigaction(SIGRTMIN, {0x3596006720, [], SA_RESTORER|SA_SIGINFO, 0x359600f500}, NULL, 8) = 0
rt_sigaction(SIGRT_1, {0x35960067b0, [], SA_RESTORER|SA_RESTART|SA_SIGINFO, 0x359600f500}, NULL, 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [RTMIN RT_1], NULL, 8) = 0
getrlimit(RLIMIT_STACK, {rlim_cur=8192*1024, rlim_max=RLIM64_INFINITY}) = 0
open("/dev/ptp0", O_RDWR) = 3
clock_gettime(0xffffffe3 /* CLOCK_??? */, {1393947888, 731912808}) = 0
open("/proc/cpuinfo", O_RDONLY) = 4
read(4, "processor\t: 0\nvendor_id\t: Genuin"..., 4096) = 3764
close(4) = 0
dup(2) = 4
fcntl(4, F_GETFL) = 0x8402 (flags O_RDWR|O_APPEND|O_LARGEFILE)
brk(0) = 0x1aa3000
brk(0x1ac4000) = 0x1ac4000
brk(0) = 0x1ac4000
fstat(4, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0f8e45c000
lseek(4, 0, SEEK_CUR) = -1 ESPIPE (Illegal seek)
write(4, "clock_gettime %m: Invalid argume"..., 35clock_gettime %m: Invalid argument
) = 35
close(4) = 0
munmap(0x7f0f8e45c000, 4096) = 0
close(3) = 0
exit_group(0) = ?
+++ exited with 0 +++
Calvin> Here is output of ltrace
[root@V4-CALVIN ptptest]# ltrace ./testptp -d /dev/ptp0 -g
unexpected breakpoint at 0x35954016df
(0, 0, 0, -1, 0x1f25bc2) = 0x3595623260
__libc_start_main(0x400ed4, 4, 0x7fff7d779898, 0x401790, 0x401820 <unfinished ...>
strrchr("./testptp", '/') = "/testptp"
getopt(4, 0x7fff7d779898, "a:A:cd:e:f:ghp:P:sSt:v") = 100
getopt(4, 0x7fff7d779898, "a:A:cd:e:f:ghp:P:sSt:v") = 103
getopt(4, 0x7fff7d779898, "a:A:cd:e:f:ghp:P:sSt:v") = -1
open("/dev/ptp0", 2, 022556611134) = 4
clock_gettime(0xffffffdb, 0x7fff7d779690, 0x7fff7d779690, -1, 0) = 0xffffffff
perror("clock_gettime %m"clock_gettime %m: Invalid argument
) = <void>
close(4) = 0
+++ exited (status 0) +++
Thanks!
Calvin
-----Original Message-----
From: Richard Cochran [mailto:ric...@gm...]
Sent: Tuesday, March 04, 2014 10:18 AM
To: Pham, Calvin
Cc: lin...@li...
Subject: Re: [Linuxptp-users] phc2sys[273995.639]: failed to read clock: Invalid argument
On Tue, Mar 04, 2014 at 01:55:56PM +0000, Pham, Calvin wrote:
>
> > testptp -g
> [root@V4-CALVIN ptp]# ./testptp -g
> gettime: CLK_ID 0xffffffe3
> clock time: 1393941119.523279956 or Tue Mar 4 08:51:59 2014
> clock_gettime %m: Invalid argument
[ It looks like you changed testptp to always print the time. ]
I looked at the igb driver, and it always returns 0 for its gettime method. So now this looks more like a glibc bug.
Can you run 'testptp -g' under strace and ltrace and post the results?
Thanks,
Richard
|
|
From: Richard C. <ric...@gm...> - 2014-03-04 16:17:42
|
On Tue, Mar 04, 2014 at 03:48:57PM +0000, Pham, Calvin wrote:
> Calvin> output of strace
> strace ./testptp -d /dev/ptp0 -g
...
> clock_gettime(0xffffffe3 /* CLOCK_??? */, {1393947888, 731912808}) = 0
The kernel returns zero.
> Calvin> Here is output of ltrace
>
> [root@V4-CALVIN ptptest]# ltrace ./testptp -d /dev/ptp0 -g
...
> clock_gettime(0xffffffdb, 0x7fff7d779690, 0x7fff7d779690, -1, 0) = 0xffffffff
But your C library returns -1.
This is a bug in your C library.
What distro and C library are you using?
Thanks,
Richard
|
|
From: Pham, C. <Cal...@ne...> - 2014-03-04 16:26:30
|
Richard,
We are running Fedora Core 16, and glibc-2.14.90-24.fc16.9.x86_64.
Thank you for your help! Now we understand why and take the next step.
Calvin
-----Original Message-----
From: Richard Cochran [mailto:ric...@gm...]
Sent: Tuesday, March 04, 2014 11:18 AM
To: Pham, Calvin
Cc: lin...@li...
Subject: Re: [Linuxptp-users] phc2sys[273995.639]: failed to read clock: Invalid argument
On Tue, Mar 04, 2014 at 03:48:57PM +0000, Pham, Calvin wrote:
> Calvin> output of strace
> strace ./testptp -d /dev/ptp0 -g
...
> clock_gettime(0xffffffe3 /* CLOCK_??? */, {1393947888, 731912808}) = 0
The kernel returns zero.
> Calvin> Here is output of ltrace
>
> [root@V4-CALVIN ptptest]# ltrace ./testptp -d /dev/ptp0 -g
...
> clock_gettime(0xffffffdb, 0x7fff7d779690, 0x7fff7d779690, -1, 0) = 0xffffffff
But your C library returns -1.
This is a bug in your C library.
What distro and C library are you using?
Thanks,
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