Incorrect clock used for set_input_skip_frame switch_time

[iskunk]

I am experimenting with Motion on a Debian GNU/Linux "stretch" system with an 8-input, 2-chip Bt878A PCI card.

I've configured Motion to read from all eight inputs, but when I run it, I get a constant stream of these log messages:

[3:ml3] [NTC] [VID] [Mar 29 23:42:21] v4l2_set_input: set_input_skip_frame switch_time=1490845341:530332
[3:ml3] [NTC] [VID] [Mar 29 23:42:21] v4l2_set_input: got frame before  switch timestamp=176707:108998
[3:ml3] [NTC] [VID] [Mar 29 23:42:21] v4l2_set_input: got frame before  switch timestamp=176707:143630

The thing to note is that the 1490845341:530332 and 176707:108998 represent timestamps that are supposed to be fairly close to each other, but here are way, way apart.

These two articles should explain what is going on:

https://stackoverflow.com/questions/10266451/where-does-v4l2-buffer-timestamp-value-starts-counting

http://linux-media.vger.kernel.narkive.com/d7SgCPur/v4l-camera-frame-timestamp-question

The fix here, then, should be to replace the call to gettimeofday() with a call to clock_gettime(CLOCK_MONOTONIC, ...). However, there are a couple things to consider:

• When this code was originally added back in 2007, the V4L driver was returning frame timestamps from the realtime clock, matching up with gettimeofday(). That is obviously not the case with the bttv driver I am using today, but it is possible that some far-flung V4L drivers still do this. This should be considered a bug and the drivers fixed, but it may be something to deal with in the present.
• It may be preferable to use the CLOCK_MONOTONIC_RAW clock instead of CLOCK_MONOTONIC here (see the clock_gettime(2) man page for details), but this is Linux-only, so the use would need to be conditional. Of course, we would need to see what the driver actually uses, since our best bet is likely to use the same clock source.
• On some systems, clock_gettime() is in the C library; on others, it is in -lrt. (It is not consistent even on Linux---the library is needed on an RHEL6 system, but not on Debian jessie or newer.)

I am attaching a small convenience program that will print out the current values of all the clocks accessible with clock_gettime(). This can be used to check the source of the timestamps in the Motion log file.

Closely related to the above:

• The timestamps are being printed to the log in a format that obscures their meaning. The two numbers are the .tv_sec and .tv_usec fields of a struct timeval, which is just seconds and microseconds. These should be printed with a format of "%ld.%06ld".
• There are currently two spaces in the "got frame before switch timestamp" message, between "before" and "switch".

[Mr-Dave]

Just trying to catch up on issues vs bugs here.

Is there a particular reason to not just use the same clock function for determining the capture of images and ignoring the time provided by the driver? Say putting the results of gettimeofday as the stamp while capturing the image. Seems easier to just stick with one clock rather than trying to sync two together.

And then with how integral times are within the entire application evaluate whether gettimeofday is the best suited function with respect to accuracy, resources, portability, etc.

[iskunk]

@Mr-Dave: Note that the code first populates switchTime, then calls v4l2_capture(), and then compares timestamps. That implies that the capture operation actually occurs in the background, rather than synchronously when v4l2_capture() is called. So if you call gettimeofday() right when you call v4l2_capture(), then you're not getting an equivalent to the driver timestamp (and the check will never fail, thus defeating its purpose).

And yes, gettimeofday() is definitely not the function that should be used for this kind of thing, because that (realtime) clock is subject to NTP slewing, leap seconds, etc. That's most likely what explains why the driver changed over to using the monotonic clock.

[Mr-Dave]

Ah yes, I needed to refresh my memory with respect to this round-robin thing (I can't test it btw).

On the considerations:

• I am not worried at the moment about the old drivers. Since the uvc team is using it, seems pretty safe. I think that if it comes up we could put in a condition somewhere to test which clock is closest to driver clock and then use that.
• I think we need to opt for the CLOCK_MONOTONIC for portability although the CLOCK_MONOTONIC_RAW seems better since it isn't adjusting.
• The library doesn't seem like a showstopper.

Has the CLOCK_MONOTONIC been tested?

[iskunk]

I think old drivers should not be an issue, unless we explicitly want to support old kernels. Given the problems with using the realtime clock, it's arguable that [a video driver] doing so should be considered a bug.

CLOCK_MONOTONIC vs. CLOCK_MONOTONIC_RAW: In principle, the latter is preferable. The real deciding factor should be what the driver is actually using. But of course, the driver code doesn't use this API, so it's not obvious which of these two is the equivalent.

Yes, librt should be no big deal; it's just an additional check. This is always a system library.

I've tested Motion with CLOCK_MONOTONIC_RAW and had no issues. But then, I'm not sure whether my hardware is prone to the frame-before-switch scenario in the first place.

Shall I put together a PR?

[Mr-Dave]

Although the CLOCK_MONOTONIC_RAW is preferable from the definition, it looks like it would fail on FreeBSD since I don't see it defined in the time.h

Obviously we could put in yet another #IF (BSD) but I'm really trying to cut down on those and limit them to only the situations in which we really really need them. And if they are needed, put them into a isolated "my" function which returns the value desired so that they don't propagate across the code.

Since the round-robin process skips frames any way as it cycles the inputs, do you think we need to be concerned about the small incremental changes that ntp may be doing to the clock that would necessitate the use of CLOCK_MONOTONIC_RAW instead of just CLOCK_MONOTONIC ? (Again, I don't have one of these cards so I have no idea of whether it makes a difference or not)

[Mr-Dave]

I have thought about this a bit more and would like to take a different tact. Since we don't know the time base of the driver, I'd like to zero it out of the calculation. Instead of comparing the two time bases directly, I think that we should store in the v4l2 context the particular value from the driver when it is initiated and at the same time store the start up time from get_time. We can then compare the differences to those times during the capture phase.

[iskunk]

Is the V4L driver usable on FreeBSD? I thought V4L was Linux-only.

I just did this in my code:

#ifndef CLOCK_MONOTONIC_RAW
# define CLOCK_MONOTONIC_RAW CLOCK_MONOTONIC
#endif

As for using a time-base offset... that's a good idea in principle, but is there a way to query the driver synchronously to get the two time values at approximately the same instant?

Remember that the time difference that is being compared in the frame-before-switch check is very small, and if these offsets aren't obtained precisely, then the check will either always fail or never fail. (Or at least, fail more or less than it should.)

If you really want to support drivers that use the realtime clock (whether in an old kernel, or a new kernel with an unmaintained driver), then IMO the better approach would be to determine whether or not the driver is using the realtime clock or not (it's pretty obvious when you see the time value) and then use either CLOCK_REALTIME or CLOCK_MONOTONIC* from then on.

[Mr-Dave]

Yes, I did get this module working with webcams on FreeBSD via the webcamd and v4l_compat packages when it was restructured.

I was anticipating grabbing the time from the first image during startup but since you can see these issues, I'm willing to go with the option of setting a "clock_type" flag to determine which to use. (I'd note that I'm most worried about the unmaintained driver scenario rather than old kernel)