[linux-uvc-devel] Bad capture timestamp conversion

[Кыштымов П. <kys...@ya...>]

<div>Hi!</div><div> </div><div>I use a Microsoft LifeCam Cinema camera connected to a Raspberry Pi 4B board to capture YUV frames, and wish to have PTS timestamps in my application, instead of system clock samples quantized at the URB boundary (~4 ms). Enabling the hwtimestamps parameter puts into service the sophisticated clock conversion code that resides in the uvc_video_clock_update function, but resulting timestamps look somewhat wierd. To say the least, timestamps for successive frames are not monotonic.</div><div> </div><div><div>uname -a</div><div><div>Linux raspberrypi 5.10.63-v7l+ #1459 SMP Wed Oct 6 16:41:57 BST 2021 armv7l GNU/Linux</div><div> </div><div>lsusb</div><div><div>Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub</div><div>Bus 001 Device 003: ID 045e:075d Microsoft Corp. LifeCam Cinema</div><div>Bus 001 Device 002: ID 2109:3431 VIA Labs, Inc. Hub</div><div>Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub</div><div>&lt;Output of lsusb -d 045e:075d -v attached in lsusb.txt&gt;</div><div> </div><div>modinfo uvcvideo</div><div><div>version:        1.1.1</div><div>&lt;full response attached in modinfo.txt&gt;</div></div></div><div> </div></div></div><div>Here is a piece of uvcvideo trace for a few seconds session (full log attached in dmesg.txt)</div><div> </div><div><div>[ 1490.494279] uvcvideo: Frame complete (EOF found).</div><div>[ 1490.494314] uvcvideo: frame 62 stats: 23/244/267 packets, 1/4/267 pts (early initial), 266/267 scr, last pts/stc/sof 4171438061/623018987/1826</div><div>[ 1490.494433] uvcvideo: uvc_v4l2_poll</div><div>[ 1490.494538] uvcvideo: Microsoft® LifeCam Cinema(TM):: PTS 4171438061 y 302681263.118759 SOF 36015.118759 (x1 2893195733 x2 2894125607 y1 252116992 y2 254148608 SOF offset 0)</div><div>[ 1490.494552] uvcvideo: Microsoft® LifeCam Cinema(TM):: SOF 33967.118759 y 31188972826 ts 1520632885720 buf ts 1490435939653 (x1 252313600/1802/1799 x2 254148608/1830/1830 y1 1000000000 y2 1028066803)</div><div>[ 1490.496271] uvcvideo: uvc_v4l2_poll</div><div>[ 1490.526238] uvcvideo: Frame complete (EOF found).</div><div>[ 1490.526270] uvcvideo: frame 63 stats: 23/244/267 packets, 1/4/267 pts (early initial), 266/267 scr, last pts/stc/sof 4172438005/624020101/1860</div><div>[ 1490.526477] uvcvideo: uvc_v4l2_poll</div><div>[ 1490.526536] uvcvideo: Microsoft® LifeCam Cinema(TM):: PTS 4172438005 y 302681296.454742 SOF 36048.454742 (x1 2893155659 x2 2894085533 y1 254214144 y2 256245760 SOF offset 0)</div><div>[ 1490.526550] uvcvideo: Microsoft® LifeCam Cinema(TM):: SOF 34000.454742 y 31118682782 ts 1520594607878 buf ts 1490471949068 (x1 254410752/1834/1831 x2 256245760/1862/1862 y1 1000000000 y2 1028000212)</div><div> </div></div><div>Please note that the ts field of the last trace message for frame 63 holds 1520594607878, that is less than frame 62's ts=1520632885720.</div><div>usbmon and uvcvideo traces show that the camera uses a 30 MHz clock for PTS/SCR samples, and I haven't noticed any anomalies in these fields of stream headers. In the log fragment above, the difference between PTS values equals 4172438005-4171438061=999944, that is 33.33 ms @30 MHz, matching the capturing rate of 30 FPS. Trace fields related to dev_sof also look reliable, unlike the reconstructed values of SOF and ts.</div><div> </div><div>Raspberry Pi 4B has both the USB 2 and 3 ports, the problem holds for both options (the log was recorded for the former).</div><div> </div><div>Could you please comment on this?</div><div> </div><div>Thank you so much for your great work!</div>