V4l2 Timestamp always 0 after VIDIOC_DQBUF (l4t r32.2.1)

[wilkinsw]

I have an app based on sample 12_camera_v4l2_cuda which takes frames from a v4l2 device and writes them to a V4L2_MEMORY_DMABUF for use with nvbuf_utils. I recently updated to kernel 4.9 (specifically l4t r32.2.1) and I noticed that the v4l2 timestamps are no longer being populated by VIDIOC_DQBUF.

I know quite a lot has changed with the update to 4.9, is there something I am missing to get the v4l2 timestamps to work?

Previously all I had to do was:

struct v4l2_buffer v4l2_buf;
memset(&v4l2_buf, 0, sizeof(struct v4l2_buffer));
v4l2_buf.type = V4L2_BUF_TYPE_VIDEO_CAPTURE;
v4l2_buf.memory = V4L2_MEMORY_DMABUF;

ioctl(cam_fd, VIDIOC_DQBUF, &v4l2_buf);

size_t timestamp = (v4l2_buf.timestamp.tv_sec * 1e6) + v4l2_buf.timestamp.tv_usec;

Now tv_sec and tv_usec are both 0.

For a test just add a printf to line ~615 of 12_camera_v4l2_cuda.cpp that prints out the timestamp fields of v4l2_buf.

$ /usr/src/tegra_multimedia_api/samples/12_camera_v4l2_cuda$ diff camera_v4l2_cuda.cpp camera_v4l2_cuda.cpp.old 
616,618d615
<             printf("tv_sec=%ld, tv_usec=%ld\n",
<                 v4l2_buf.timestamp.tv_sec, v4l2_buf.timestamp.tv_usec);
< 

Thanks!

[ShaneCCC]

Using the vb2_v4l2_buffer instead of the v4l2_buffer.

struct vb2_v4l2_buffer {
	struct vb2_buffer	vb2_buf;

	__u32			flags;
	__u32			field;
	struct v4l2_timecode	timecode;
	__u32			sequence;
};

struct vb2_buffer {
	struct vb2_queue	*vb2_queue;
	unsigned int		index;
	unsigned int		type;
	unsigned int		memory;
	unsigned int		num_planes;
	struct vb2_plane	planes[VB2_MAX_PLANES];
	u64			timestamp;

	/* private: internal use only
	 *
	 * state:		current buffer state; do not change
	 * queued_entry:	entry on the queued buffers list, which holds
	 *			all buffers queued from userspace
	 * done_entry:		entry on the list that stores all buffers ready
	 *			to be dequeued to userspace
	 */
	enum vb2_buffer_state	state;

	struct list_head	queued_entry;
	struct list_head	done_entry;
#ifdef CONFIG_VIDEO_ADV_DEBUG
	/*
	 * Counters for how often these buffer-related ops are
	 * called. Used to check for unbalanced ops.
	 */
	u32		cnt_mem_alloc;
	u32		cnt_mem_put;
	u32		cnt_mem_get_dmabuf;
	u32		cnt_mem_get_userptr;
	u32		cnt_mem_put_userptr;
	u32		cnt_mem_prepare;
	u32		cnt_mem_finish;
	u32		cnt_mem_attach_dmabuf;
	u32		cnt_mem_detach_dmabuf;
	u32		cnt_mem_map_dmabuf;
	u32		cnt_mem_unmap_dmabuf;
	u32		cnt_mem_vaddr;
	u32		cnt_mem_cookie;
	u32		cnt_mem_num_users;
	u32		cnt_mem_mmap;

	u32		cnt_buf_init;
	u32		cnt_buf_prepare;
	u32		cnt_buf_finish;
	u32		cnt_buf_cleanup;
	u32		cnt_buf_queue;

	/* This counts the number of calls to vb2_buffer_done() */
	u32		cnt_buf_done;
#endif
};

[wilkinsw]

I am running into the same problems as this thread:

V4L2 Time Stamp does not work for L4T 28.1 (Jetpack 3.1)

Our V4L2 based applications do not work after updating to L4T 28.1 and I tracked down it’s V4L time stamp issue. The V4L2 buffer sequence(frame number), timestamp.tv_sec(second value), timestamp.tv_us (micro-second value) are all zero now. It seems changes made in L4T 28.1 prevented time stamp of V4L2 buffer being populated.

Where trying to include “videobuf2-v4l2.h” from the kernel headers causes all sorts of problems.

[ShaneCCC]

Have a print the timestamp from the vi4_fops.c kernel driver to confirm.

[wilkinsw]

Just to clarify, I should be passing a vb2_v4l2_buffer into ioctl with VIDIOC_DQBUF instead of a regular v4l2_buf?

[ShaneCCC]

Should be the vb2_buffer

[wilkinsw]

vb2_buffer is defined in videobuf2-core.h which is only available in the kernel source. Trying to include it in user space causes a whole host of issues.

When that failed I spent some time trying to cherry pick out the struct definitions (vb2_buffer, vb2_queue, vb2_plane, etc) but that quickly got down to some includes only available in the kernel source.

I don’t think that using vb2_buffer (or vb2_v4l2_buffer) is an option in user space.

[wilkinsw]

As requested I placed a print in vi4_fops.c at the end of tegra_channel_capture_frame_single_thread that prints the contents of struct timespec ts

@@ -570,6 +594,11 @@ static int tegra_channel_capture_frame_single_thread(
 
        tegra_channel_ring_buffer(chan, vb, &ts, state);
        trace_tegra_channel_capture_frame("sof", ts);
+
+    dev_info(chan->vi->dev, "%s: ts.tv_sec=%ld, ts.tv_nsec=%ld\n",
+        __func__, ts.tv_sec, ts.tv_nsec);
+
        return 0;
 }

dmesg results:

[   54.782477] tegra-vi4 15700000.vi: tegra_channel_capture_frame_single_thread: ts.tv_sec=54, ts.tv_nsec=674887488
[   54.815499] tegra-vi4 15700000.vi: tegra_channel_capture_frame_single_thread: ts.tv_sec=54, ts.tv_nsec=707917536
[   54.848539] tegra-vi4 15700000.vi: tegra_channel_capture_frame_single_thread: ts.tv_sec=54, ts.tv_nsec=740947520
[   54.881560] tegra-vi4 15700000.vi: tegra_channel_capture_frame_single_thread: ts.tv_sec=54, ts.tv_nsec=773977504

This shows that the timestamp is at least being generated in the driver.

[ShaneCCC]

Could you add the V4L2_BUF_FLAG_TIMESTAMP_COPY flag to kernel driver to try.

diff --git a/drivers/media/platform/tegra/camera/vi/channel.c b/drivers/media/platform/tegra/camera/vi/channel.c
index 6a2777e..dbe1670 100644
--- a/drivers/media/platform/tegra/camera/vi/channel.c
+++ b/drivers/media/platform/tegra/camera/vi/channel.c
@@ -2319,7 +2319,7 @@ int tegra_channel_init(struct tegra_channel *chan)
        chan->queue.mem_ops = &vb2_dma_contig_memops;
 #endif
        chan->queue.timestamp_flags = V4L2_BUF_FLAG_TIMESTAMP_MONOTONIC
-                                  | V4L2_BUF_FLAG_TSTAMP_SRC_EOF;
+                                  | V4L2_BUF_FLAG_TSTAMP_SRC_EOF | V4L2_BUF_FLAG_TIMESTAMP_COPY;
        ret = vb2_queue_init(&chan->queue);
        if (ret < 0) {
                dev_err(chan->vi->dev, "failed to initialize VB2 queue\n");

[wilkinsw]

I added the flag, but the timestamp is still zero.

Just to be clear I am still using a v4l2_buffer with ioctl VIDIOC_DQBUF just like sample 12_camera_v4l2_cuda since I was unable to include the definition for vb2_buffer.

[ShaneCCC]

From below code in …/camera/vi/channel.c
You may use the timecode for the solution.

void set_timestamp(struct tegra_channel_buffer *buf,
			const struct timespec *ts)
{
#if LINUX_VERSION_CODE < KERNEL_VERSION(4, 9, 0)
	/* update time stamp of the buffer */
	buf->buf.timestamp.tv_sec = ts->tv_sec;
	buf->buf.timestamp.tv_usec = ts->tv_nsec / NSEC_PER_USEC;
#else
	/* TODO: granular time code information */
	buf->buf.timecode.seconds = ts->tv_sec;
#endif
}

[wilkinsw]

I don’t think that’s working either. Each of the timecode fields are 8-bit so I added the following code:

void set_timestamp(struct tegra_channel_buffer *buf,
            const struct timespec *ts)
{
#if LINUX_VERSION_CODE < KERNEL_VERSION(4, 9, 0)
    /* update time stamp of the buffer */
    buf->buf.timestamp.tv_sec = ts->tv_sec;
    buf->buf.timestamp.tv_usec = ts->tv_nsec / NSEC_PER_USEC;
#else
    /* Begin timecode */
    u32 nsec = ts->tv_nsec;
    buf->buf.timecode.hours = ts->tv_sec / 3600;
    buf->buf.timecode.minutes = (ts->tv_sec % 3600) / 60;
    buf->buf.timecode.seconds = (ts->tv_sec % 60);
    memcpy(buf->buf.timecode.userbits, &nsec, 4);
    /* End timecode */

    buf->buf.vb2_buf.timestamp = timespec_to_ns(ts);
#endif
}

In my app I was excited to see that timecode.seconds was incrementing, however the value continued to increment past 60 which shouldn’t be possible since I am setting it with a modulus of 60. The other fields (hours, minutes, and userbits) were all 0. Could there be something downstream that is using the timecode field already?

[ShaneCCC]

I mean have the APP to get the timecode instead to modify the kernel driver.
Modify the 12_camera_v4l2_cuda to get the v4l2_buf.timecode for the frame timestamp as WAR.

[Camera_Engg_Nvidia]

Are you able to see other v4l2_buffer fields like the sequence and index?

[wilkinsw]

@ShaneCCC timecode isn’t going to work for my application. I am using the timestamps to do a rough synchronization of two V4L2 streams so I really need the microseconds/nanoseconds.

@Camera_Engg_Nvidia Looks like most fields are accounted for:

v4l2_buffer {
    .index=1
    .type=1
    .bytesused=1843200
    .flags=8192
    .field=1
    .timestamp {
        .tv_sec=0
        .tv_usec=0
    }
    .timecode {
        .type=0
        .flags=0
        .frames=0
        .seconds=45
        .minutes=0
        .hours=0
    }
    .sequence=1
    .memory=4
    .length=1843200
}
...
v4l2_buffer {
    .index=3
    .type=1
    .bytesused=1843200
    .flags=8192
    .field=1
    .timestamp {
        .tv_sec=0
        .tv_usec=0
    }
    .timecode {
        .type=0
        .flags=0
        .frames=0
        .seconds=46
        .minutes=0
        .hours=0
    }
    .sequence=31
    .memory=4
    .length=1843200
}

I should mention that the video itself is working. Data shows up after NvBufferMemSyncForDevice and I can use nvbuf_utils to manipulate it.

[wilkinsw]

Any movement on this?

[ShaneCCC]

Due to the structure of the timestamp in the vb2_buffer change to u64. It’s different with timestamp struct in the v4l2_buffer.
VI driver set the timestamp by timespec_to_ns(ts), could you check if it’s validate time in the v4l2_buf.timestamp by u64

struct vb2_buffer {
	struct vb2_queue	*vb2_queue;
	unsigned int		index;
	unsigned int		type;
	unsigned int		memory;
	unsigned int		num_planes;
	struct vb2_plane	planes[VB2_MAX_PLANES];
	u64			timestamp;
..
..
..
    }

struct v4l2_buffer {
	__u32			index;
	__u32			type;
	__u32			bytesused;
	__u32			flags;
	__u32			field;
	struct timeval		timestamp;
..
..
    }

[ShaneCCC]

I can get the timestamp from the v4l2-ctl by --verbose

nvidia@nvidia-desktop:~$ v4l2-ctl --set-fmt-video=width=1920,height=1080,pixelformat=RG10 --set-ctrl bypass_mode=0 --stream-mmap --stream-count=10 -d /dev/video1 --verbose
VIDIOC_QUERYCAP: ok
VIDIOC_S_EXT_CTRLS: ok
VIDIOC_G_FMT: ok
VIDIOC_S_FMT: ok
Format Video Capture:
        Width/Height      : 2592/1944
        Pixel Format      : 'RG10'
        Field             : None
        Bytes per Line    : 5376
        Size Image        : 10450944
        Colorspace        : sRGB
        Transfer Function : Default (maps to sRGB)
        YCbCr/HSV Encoding: Default (maps to ITU-R 601)
        Quantization      : Default (maps to Full Range)
        Flags             :
VIDIOC_REQBUFS: ok
VIDIOC_QUERYBUF: ok
VIDIOC_QBUF: ok
VIDIOC_QUERYBUF: ok
VIDIOC_QBUF: ok
VIDIOC_QUERYBUF: ok
VIDIOC_QBUF: ok
VIDIOC_QUERYBUF: ok
VIDIOC_QBUF: ok
VIDIOC_STREAMON: ok
        Index    : 0
        Type     : Video Capture
        Flags    : mapped
        Field    : None
        Sequence : 0
        Length   : 10450944
        Bytesused: 10450944
        Timestamp: 104.523741s (Monotonic, End-of-Frame)

        Index    : 1
        Type     : Video Capture
        Flags    : mapped
        Field    : None
        Sequence : 1
        Length   : 10450944
        Bytesused: 10450944
        Timestamp: 104.557072s (Monotonic, End-of-Frame)

        Index    : 2
        Type     : Video Capture
        Flags    : mapped
        Field    : None
        Sequence : 2
        Length   : 10450944
        Bytesused: 10450944
        Timestamp: 104.590403s (Monotonic, End-of-Frame)

        Index    : 3
        Type     : Video Capture
        Flags    : mapped
        Field    : None
        Sequence : 3
        Length   : 10450944
        Bytesused: 10450944
        Timestamp: 104.623734s (Monotonic, End-of-Frame)

[JerryChang]

hello Atrer,

please note that, after kernel-4.9, it’ll only return timestamp (i.e. sof_ts) which represent it as nanoseconds.
you might refer to below,

 struct vi_capture_status {
  ...
   	u64 sof_ts;	/* timestamp of START_OF_FRAME */

in the VI4 driver, it’ll convert by ns_to_timespec() to fill-in timespec,
could you please enable that debug prints to check sof_ts still return correct values.
thanks

static bool vi_notify_wait(struct tegra_channel *chan,
  		struct tegra_channel_buffer *buf,
  		struct timespec *ts)
{
...
  			else {
  				*ts = ns_to_timespec((s64)status.sof_ts);
  
  				dev_dbg(&chan->video->dev,
  					"%s: vi4 got SOF syncpt buf[%p]\n",
  					__func__, buf);

[wilkinsw]

@ShaneCCC I am getting 0 for timestamp with v4l2-ctl also:

VIDIOC_QUERYCAP: ok
VIDIOC_G_FMT: ok
VIDIOC_S_FMT: ok
Format Video Capture:
	Width/Height      : 1280/720
	Pixel Format      : 'UYVY'
	Field             : None
	Bytes per Line    : 2560
	Size Image        : 1843200
	Colorspace        : SMPTE 170M
	Transfer Function : Default (maps to Rec. 709)
	YCbCr/HSV Encoding: Default (maps to ITU-R 601)
	Quantization      : Default (maps to Limited Range)
	Flags             : 
New timings found
VIDIOC_REQBUFS: ok
VIDIOC_QUERYBUF: ok
VIDIOC_QBUF: ok
VIDIOC_QUERYBUF: ok
VIDIOC_QBUF: ok
VIDIOC_QUERYBUF: ok
VIDIOC_QBUF: ok
VIDIOC_QUERYBUF: ok
VIDIOC_QBUF: ok
VIDIOC_STREAMON: ok
	Index    : 0
	Type     : Video Capture
	Flags    : mapped
	Field    : None
	Sequence : 0
	Length   : 1843200
	Bytesused: 1843200
	Timestamp: 0.000000s (Monotonic, End-of-Frame)

	Index    : 1
	Type     : Video Capture
	Flags    : mapped
	Field    : None
	Sequence : 1
	Length   : 1843200
	Bytesused: 1843200
	Timestamp: 0.000000s (Monotonic, End-of-Frame)

	Index    : 2
	Type     : Video Capture
	Flags    : mapped
	Field    : None
	Sequence : 2
	Length   : 1843200
	Bytesused: 1843200
	Timestamp: 0.000000s (Monotonic, End-of-Frame)

	Index    : 3
	Type     : Video Capture
	Flags    : mapped
	Field    : None
	Sequence : 3
	Length   : 1843200
	Bytesused: 1843200
	Timestamp: 0.000000s (Monotonic, End-of-Frame)

	Index    : 0
	Type     : Video Capture
	Flags    : mapped
	Field    : None
	Sequence : 4
	Length   : 1843200
	Bytesused: 1843200
	Timestamp: 0.000000s (Monotonic, End-of-Frame)

	Index    : 1
	Type     : Video Capture
	Flags    : mapped
	Field    : None
	Sequence : 5
	Length   : 1843200
	Bytesused: 1843200
	Timestamp: 0.000000s (Monotonic, End-of-Frame)

	Index    : 2
	Type     : Video Capture
	Flags    : mapped
	Field    : None
	Sequence : 6
	Length   : 1843200
	Bytesused: 1843200
	Timestamp: 0.000000s (Monotonic, End-of-Frame)

	Index    : 3
	Type     : Video Capture
	Flags    : mapped
	Field    : None
	Sequence : 7
	Length   : 1843200
	Bytesused: 1843200
	Timestamp: 0.000000s (Monotonic, End-of-Frame)

	Index    : 0
	Type     : Video Capture
	Flags    : mapped
	Field    : None
	Sequence : 8
	Length   : 1843200
	Bytesused: 1843200
	Timestamp: 0.000000s (Monotonic, End-of-Frame)

	Index    : 1
	Type     : Video Capture
	Flags    : mapped
	Field    : None
	Sequence : 9
	Length   : 1843200
	Bytesused: 1843200
	Timestamp: 0.000000s (Monotonic, End-of-Frame)

VIDIOC_STREAMOFF: ok