Actions
Bug #1168
openCTF for a user-plugged clock assumes that "offset" is unsigned, but a negative value can happen and will result in unparsable metadata getting stored
Status:
Feedback
Priority:
Normal
Assignee:
-
Category:
-
Target version:
-
Start date:
05/31/2018
Due date:
% Done:
0%
Estimated time:
Description
Hi,
I need to switch LTTng timestamp source to CLOCK_REALTIME from CLOCK_MONOTONIC in order to correlate with hardware-generated timestamps in a NIC. My initial attempt was easy enough to get going as a clock plugin:
static uint64_t
my_clock_time ()
{
struct timespec t;
clock_gettime (CLOCK_REALTIME, & t);
return (t.tv_sec * 1000000000UL + t.tv_nsec);
}
static uint64_t
my_clock_freq ()
{
return 1000000000UL;
}
(the rest follows the "clock-override" example). However, this results in sporadic errors opening the trace later via babeltrace:
[error] ctf_clock_declaration_visit: unexpected unary expression for clock offset [error] ctf_visitor_construct_metadata: clock declaration error [error] Error in CTF metadata constructor -22 [warning] Unable to open trace metadata for path "/.../ust/pid/...-115227-20180601-062437". [warning] [Context] Cannot open_trace of format ctf at path /...-115227-20180601-062437.
It appears that this happens when LTTng calculates the clock's "epoch offset" (which in theory should be 0 above) and it comes out as a small negative number. To reproduce this every time, try shifting the my_clock_value() result:
static uint64_t
my_clock_time ()
{
struct timespec t;
clock_gettime (CLOCK_REALTIME, & t);
return (t.tv_sec * 1000000000UL + t.tv_nsec + 1000);
}
Peeking inside the persisted "metadata" you will see something like this:
>hexdump -C /...-115227-20180601-062437/metadata | less
...
00000440 4c 54 49 4d 45 22 3b 0a 09 66 72 65 71 20 3d 20 |LTIME";..freq = |
00000450 31 30 30 30 30 30 30 30 30 30 3b 20 2f 2a 20 46 |1000000000; /* F|
00000460 72 65 71 75 65 6e 63 79 2c 20 69 6e 20 48 7a 20 |requency, in Hz |
00000470 2a 2f 0a 09 2f 2a 20 63 6c 6f 63 6b 20 76 61 6c |*/../* clock val|
00000480 75 65 20 6f 66 66 73 65 74 20 66 72 6f 6d 20 45 |ue offset from E|
00000490 70 6f 63 68 20 69 73 3a 20 6f 66 66 73 65 74 20 |poch is: offset |
000004a0 2a 20 28 31 2f 66 72 65 71 29 20 2a 2f 0a 09 6f |* (1/freq) */..o|
000004b0 66 66 73 65 74 20 3d 20 2d 31 30 30 31 3b 0a 7d |ffset = -1001;.}| <- negative value stored as "signed = false" int?
000004c0 3b 0a 0a 74 79 70 65 61 6c 69 61 73 20 69 6e 74 |;..typealias int|
000004d0 65 67 65 72 20 7b 0a 09 73 69 7a 65 20 3d 20 32 |eger {..size = 2|
000004e0 37 3b 20 61 6c 69 67 6e 20 3d 20 31 3b 20 73 69 |7; align = 1; si|
000004f0 67 6e 65 64 20 3d 20 66 61 6c 73 65 3b 0a 09 6d |gned = false;..m|
My env details (both lttng and babeltrace were built from stable sources):
>lttng --version lttng (LTTng Trace Control) 2.10.4 - KeKriek >lttng-sessiond --version 2.10.4 >babeltrace --version BabelTrace Trace Viewer and Converter 1.5.5 >uname -a Linux ... 3.10.0-693.11.6.el7.x86_64 #1 SMP Thu Jan 4 01:06:37 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux >cat /etc/system-release CentOS Linux release 7.4.1708 (Core) >nproc 16
Actions