Plot, score, and log timestamp intervals for analysis

[Cybis320]

This PR introduces PlotTimeIntervals.py, a utility that generates a plot displaying the intervals between FF file timestamps. It also assigns a score ranging from 0 to 1000, with higher scores indicating less variability in the timestamps.

During reprocessing, this utility is invoked on the night_dir, logging a score and incorporating it into the plot's filename. If insufficient intervals are present to calculate a meaningful score, none is returned. The plot and score aim to function as diagnostic tools for identifying timestamping and dropped frame issues.

The utility uses Pandas to find outliers, and pandas has been added to requirements.txt. If this is a pain point, the utility can be redisigned without this feature.

The scoring is somewhat arbritary and designed to offer what feels like the right sensitivity. What are your thoughts?

Edit: Denis, thank you for suggesting to use tar.bz2 - I've incorporated that suggestion.

[Cybis320]

That makes sense. I don't know anything about the weblog so that's probably not something I'd be comfortable doing unless there's an example I can follow.

[g7gpr]

Still got a problem with an edge case, on a directory which contains no .fits files. This can happen if a camera power supply fails, which happens from time to time.

(vRMS) au000u@pioneer:~/source/RMS$ git log -1
commit ea699217c524463dd413a4a730bcff9b44d848aa (HEAD -> intervals, cybis320/intervals)
Author: Denis Vida <denis.vida@gmail.com>
Date:   Thu Feb 8 11:56:53 2024 -0500

    Added residuals plot
(vRMS) au000u@pioneer:~/source/RMS$ python -m Utils.PlotTimeIntervals ~/RMS_data/ArchivedFiles/
Loading config file: /home/au000u/RMS_data/ArchivedFiles/AU000U_20240123_114744_582540/.config
Processing /home/au000u/RMS_data/ArchivedFiles/AU000U_20240123_114744_582540/FS_AU000U_20240123_114744_582540_fieldsums.tar.bz2
Loading config file: /home/au000u/RMS_data/ArchivedFiles/AU000U_20240125_114644_582696/.config
Processing /home/au000u/RMS_data/ArchivedFiles/AU000U_20240125_114644_582696/FS_AU000U_20240125_114644_582696_fieldsums.tar.bz2
Loading config file: /home/au000u/RMS_data/ArchivedFiles/AU000U_20240204_114011_242936/.config
Processing /home/au000u/RMS_data/ArchivedFiles/AU000U_20240204_114011_242936/FS_AU000U_20240204_114011_242936_fieldsums.tar.bz2
Loading config file: /home/au000u/RMS_data/ArchivedFiles/AU000U_20240201_114224_817694/.config
Processing /home/au000u/RMS_data/ArchivedFiles/AU000U_20240201_114224_817694/FS_AU000U_20240201_114224_817694_fieldsums.tar.bz2
Loading config file: /home/au000u/RMS_data/ArchivedFiles/AU000U_20240124_114714_747828/.config
Processing /home/au000u/RMS_data/ArchivedFiles/AU000U_20240124_114714_747828/FS_AU000U_20240124_114714_747828_fieldsums.tar.bz2
Loading config file: /home/au000u/RMS_data/ArchivedFiles/AU000U_20240131_114307_048976/.config
Processing /home/au000u/RMS_data/ArchivedFiles/AU000U_20240131_114307_048976/FS_AU000U_20240131_114307_048976_fieldsums.tar.bz2
Loading config file: /home/au000u/RMS_data/ArchivedFiles/AU000U_20240203_063937_481003/.config
Processing /home/au000u/RMS_data/ArchivedFiles/AU000U_20240203_063937_481003/FS_AU000U_20240203_063937_481003_fieldsums.tar.bz2
/home/au000u/vRMS/lib/python3.9/site-packages/numpy/core/fromnumeric.py:3432: RuntimeWarning: Mean of empty slice.
  return _methods._mean(a, axis=axis, dtype=dtype,
/home/au000u/vRMS/lib/python3.9/site-packages/numpy/core/_methods.py:190: RuntimeWarning: invalid value encountered in double_scalars
  ret = ret.dtype.type(ret / rcount)
/home/au000u/vRMS/lib/python3.9/site-packages/numpy/core/_methods.py:265: RuntimeWarning: Degrees of freedom <= 0 for slice
  ret = _var(a, axis=axis, dtype=dtype, out=out, ddof=ddof,
/home/au000u/vRMS/lib/python3.9/site-packages/numpy/core/_methods.py:223: RuntimeWarning: invalid value encountered in divide
  arrmean = um.true_divide(arrmean, div, out=arrmean, casting='unsafe',
/home/au000u/vRMS/lib/python3.9/site-packages/numpy/core/_methods.py:257: RuntimeWarning: invalid value encountered in double_scalars
  ret = ret.dtype.type(ret / rcount)
Traceback (most recent call last):
  File "/usr/lib/python3.9/runpy.py", line 197, in _run_module_as_main
    return _run_code(code, main_globals, None,
  File "/usr/lib/python3.9/runpy.py", line 87, in _run_code
    exec(code, run_globals)
  File "/home/au000u/source/RMS/Utils/PlotTimeIntervals.py", line 297, in <module>
    plotFFTimeIntervals(root, fps)
  File "/home/au000u/source/RMS/Utils/PlotTimeIntervals.py", line 157, in plotFFTimeIntervals
    label='Intervals, max ({:.3f}s), min ({:.3f}s)'.format(max_interval, min_interval), 
![AU000U_20240123_114744_582540_ff_intervals](https://github.com/CroatianMeteorNetwork/RMS/assets/77130399/62a8252b-1f35-47ec-aba3-f59b6e9ae824)

TypeError: unsupported format string passed to NoneType.__format__

The chart are looking fantastic

[Cybis320]

Still got a problem with an edge case, on a directory which contains no .fits files. This can happen if a camera power supply fails, which happens from time to time.

My bad, I should have handled those cases. When you have a chance could you try this fix. Thank you!

[g7gpr]

Looking good.

Loading config file: /home/au000u/RMS_data/ArchivedFiles/AU000U_20240203_063937_481003/.config
Processing /home/au000u/RMS_data/ArchivedFiles/AU000U_20240203_063937_481003/FS_AU000U_20240203_063937_481003_fieldsums.tar.bz2
Insufficient timestamps. At least two timestamps are required.
Loading config file: /home/au000u/RMS_data/ArchivedFiles/AU000U_20240130_114346_974032/.config
Processing /home/au000u/RMS_data/ArchivedFiles/AU000U_20240130_114346_974032

AU0028 processed with no problems. Thank you for the rapid fix. It is difficult for me to test for the next few hours as the uploads are taking place, but I will report back 12 hours from now after rolling out on au000u-z and au0028-f

Dave

[g7gpr]

No problems with any of test directories. Would you consider adding a check to make sure that the specified directory exists?

[Cybis320]

No problems with any of test directories. Would you consider adding a check to make sure that the specified directory exists?

Done.

Also, I'm curious about what the resolution will be regarding the misbehaving machines. Are the issues due to slow/worn-out SD cards, or file system corruption? And if so, I'm wondering how the GStreamer branch (PR# 257) would behave on such machines. I'm concerned that the GStreamer appsink might swell up and then suddenly flush past a certain threshold, leading to large gaps in data. On the other hand, GStreamer handles temporary slowdowns without impacting timestamps, so maybe it could operate with degrading SD cards longer? (I'm struggling to make the GStreamer appsink behave less radically. Ideally, the sink should just drop frames piecemeal to prevent blowing up.)

[dvida]

BTW, I think the accuracy with gstreamer is even better, but it's currently limited by the time precision in the FF file name. We should add the more accurate time to the FF fits header with the accuracy of microseconds.

[Cybis320]

BTW, I think the accuracy with gstreamer is even better, but it's currently limited by the time precision in the FF file name. We should add the more accurate time to the FF fits header with the accuracy of microseconds.

You're right that we a losing a little bit by rounding to the mills. Here's a plot with the minimum scale disabled:

[dvida]

BTW, do you have an idea why the median is always so consistently above the expected?

[Cybis320]

BTW, do you have an idea why the median is always so consistently above the expected?

I'm guessing the camera's clock is misconfigured? The offset is pretty consistent across cameras, ~1 second per 20 minutes. It's consistent btw CV2 and Gst. It's exactly one frame per 5x 256 block run... hmm.

[Cybis320]

There is a NTSC standard for 23.976 fps. I wonder if the camera is adjusting the fps relative to that, 24.976 is exactly what we have. Maybe setting the camera to PAL will solve that?

[dvida]

We do recommend setting the camera to PAL already, check if yours is set to that. All other GMN cameras should already be set to PAL.

[Cybis320]

We do recommend setting the camera to PAL already, check if yours is set to that. All other GMN cameras should already be set to PAL.

I just checked and it was on PAL. However, setting it to NTSC or PAL does not affect the intervals. Still ~24.98 fps. At 20 fps I get ~19.98.

[dvida]

Hmmm... I wonder if it's an effect because we have two buffers and each perhaps gets timestamped differently? If we compute the time diff between ever other FF file, do we get the right number?

[Cybis320]

Hmmm... I wonder if it's an effect because we have two buffers and each perhaps gets timestamped differently? If we compute the time diff between ever other FF file, do we get the right number?

I just measured the fps independently of the compression and I'm getting the same. 24.982.

[satmonkey]

NTSC fps is 29.97. I think they use the 5/6 divider for PAL to maintain the compatibility. This yields 24.98 fps for PAL. https://steinberg.help/wavelab_pro/v10/en/wavelab/topics/video/video_frame_rates_c.html

[dvida]

Well, I'll be damned... Milan, are you seeing the same FPS with your gstreamer setup?

[Cybis320]

There's more going on. I need to graph the timestamp of each frame over time but there something non-linear happening. It looks like it's maintaining 25.0000 fps for ~27sec then dips for a few seconds before going back to exactly 25, rinse, repeat.

[Cybis320]

And same at 24fps. 24.0000 then dip.

[dvida]

Are you running the camera at 1080p? Have you tried 720p? I remember we had FPS issues at 1080p. Also, do you think it would be worth extending the FF format with per-frame timestamps? That way we can avoid any FPS issues.

[Cybis320]

The camera is running on a 1/90000 sec heartbeat would that have anything to do with anything.

720p right now.

[Cybis320]

It's a clock synching issue. By setting buffer-mode to only use RTP timestamps (buffer-mode=0) or by synchronizing sender and receiver clock (buffer-mode=4), the fps is a steady 25.0000. I need to check how either of these options impact absolute time accuracy.

[Cybis320]

Ok, it's even weirder than I imagined. First, changing buffer-mode only moves the problem down the line. I.e. when pinning the fps to 25, it causes the pts to accumulate errors over time.

Here's the really weird thing: what appears to be going on is that the camera is actually recording at 29.97 fps and dropping a 1 out of every 6 frames. I recorded a spinning disc with a dot (on a drill). The dots are evenly spaced, except every 6th dot is missing:

***** ***** ***** *****

There is on average 24.98 dots per seconds, so including the missing dot... ta-da 29.97 fps.

[Cybis320]

Ok, it's even weirder than I imagined. First, changing buffer-mode only moves the problem down the line. I.e. when pinning the fps to 25, it causes the pts to accumulate errors over time.

Here's the really weird thing: what appears to be going on is that the camera is actually recording at 29.97 fps and dropping a 1 out of every 6 frames. I recorded a spinning disc with a dot (on a drill). The dots are evenly spaced, except every 6th dot is missing:

***** ***** ***** *****

There is on average 24.98 dots per seconds, so including the missing dot... ta-da 29.97 fps.

Apologies for the confusion, I had left the camera in NTSC for that test. In PAL, it doesn't skip frames. Phew. I learned that NTSC unlocks 30 fps though.

[g7gpr]

It was weird, I have stacked frames of long lasting meteors, the angular distance moved per frame is roughly constant.

This is brilliant work though. Thanks for what you are doing.

Kind regards

David Rollinson

I am writing this on a phone, apologies for brevity and errors.

---

From: Luc Busquin @.> Sent: Thursday, February 15, 2024 3:23:11 PM To: CroatianMeteorNetwork/RMS @.> Cc: David Rollinson @.>; Mention @.> Subject: Re: [CroatianMeteorNetwork/RMS] Plot, score, and log timestamp intervals for analysis (PR #260)

Ok, it's even weirder than I imagined. First, changing buffer-mode only moves the problem down the line. I.e. when pinning the fps to 25, it causes the pts to accumulate errors over time.

Here's the really weird thing: what appears to be going on is that the camera is actually recording at 29.97 fps and dropping a 1 out of every 6 frames. I recorded a spinning disc with a dot (on a drill). The dots are evenly spaced, except every 6th dot is missing:

---

There is on average 24.98 dots per seconds, so including the missing dot... ta-da 29.97 fps.

Apologies for the confusion, I had left the camera in NTSC for that test. In PAL, it doesn't skip frames. Phew. I learned that NTSC unlocks 30 fps though.

— Reply to this email directly, view it on GitHubhttps://github.com/CroatianMeteorNetwork/RMS/pull/260#issuecomment-1945497231, or unsubscribehttps://github.com/notifications/unsubscribe-auth/ASMOVH6BAOEUV6ZLJ4QEHHDYTWZV7AVCNFSM6AAAAABCSIV2CWVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTSNBVGQ4TOMRTGE. You are receiving this because you were mentioned.Message ID: @.***>

[satmonkey]

this is the graph from pi4 buster

[satmonkey]

by the way, I can see some artefacts on the captured stack, coming from 3 FF files. This did not happen before with ffmpeg on that station. Will monitor this during a few upcoming nights and report then.

[Cybis320]

by the way, I can see some artefacts on the captured stack, coming from 3 FF files. This did not happen before with ffmpeg on that station. Will monitor this during a few upcoming nights and report then.

By the look at the plot and the gaps in the trails, there is a lot of dropped frames. I would guess there's likely a hardware issue, no?

[satmonkey]

from the reports, this does not seem so. Fine, I will make another test on another pi4 Buster.

[satmonkey]

ahh you mean those landing/taking off plane trails? That's 5 km far from the LKPR runway 24.

[Cybis320]

And that was with the dev branch which has the same capture mechanism as master?

[satmonkey]

I have just checkouted the dev and put force_cv2 into .config.

[Cybis320]

ahh you mean those landing/taking off plane trails? That's 5 km far from the LKPR runway 24.

Nice! I use to fly into PRG back in the days. And, yes, the aircraft light trails are showing gaps. Can I ask what SD cards are you using?

[satmonkey]

I see now the BufferedCapture patch was not merged into dev yet, so yes, still the old method.

[satmonkey]

Here, I use the USB3 256GB Sandisk flash disk , running in the high speed mode. (vRMS) pi@raspberrypi:~/source $ lsusb -t /: Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/4p, 5000M | Port 2: Dev 2, If 0, Class=Mass Storage, Driver=usb-storage, 5000M /: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/1p, 480M | Port 1: Dev 2, If 0, Class=Hub, Driver=hub/4p, 480M

[Cybis320]

I get 33.0 MB/s for write and 45.3 MB/s for read on a RPi4 Bookworm with a Sandisk Extreme Pro SD card.

(vRMS) pi@rpi4-cam:~/source/RMS $ dd if=/dev/zero of=tempfile bs=1M count=1024 conv=fdatasync,notrunc
1024+0 records in
1024+0 records out
1073741824 bytes (1.1 GB, 1.0 GiB) copied, 32.5159 s, 33.0 MB/s

(vRMS) pi@rpi4-cam:~/source/RMS $ sudo /sbin/sysctl -w vm.drop_caches=3
vm.drop_caches = 3
(vRMS) pi@rpi4-cam:~/source/RMS $ dd if=tempfile of=/dev/null bs=1M count=1024
1024+0 records in
1024+0 records out
1073741824 bytes (1.1 GB, 1.0 GiB) copied, 23.7063 s, 45.3 MB/s

[Cybis320]

For fun: write: 466 MB/s and read: 384 MB/s with RPi5 with NVMe SSD:

root@rpi-cam1:~# dd if=/dev/zero of=tempfile bs=1M count=1024 conv=fdatasync,notrunc
1024+0 records in
1024+0 records out
1073741824 bytes (1.1 GB, 1.0 GiB) copied, 2.79917 s, 384 MB/s

root@rpi-cam1:~# dd if=tempfile of=/dev/null bs=1M count=1024
1024+0 records in
1024+0 records out
1073741824 bytes (1.1 GB, 1.0 GiB) copied, 2.30412 s, 466 MB/s

[Cybis320]

Here's where I'm at with the frame rate. Even in PAL, the actual fps is ~24.982, and each frame is very evenly spaced with no significant variations (there may be some tiny variation over long periods.)

Unfortunately, the rtspsrc element is expecting exactly 25 fps, and is always attempting to go back to 25 fps. This causes the slight dips when the error reaches about 1 ms and the pts algorithm more or less smoothly adjust the pts to zero the error. It does this in a ~27s cycle with an amplitude of ~3ms. I don't see an easy way to tell the first element of the pipeline to expect 24.982 fps. It might be "easier" to write a pts smoothing algorithm in python if we want sub ms precision.

For the FF files, the first frame timestamp should be accurate to ~10ms (given the start time uncertainty and the pts wandering). Assuming 24.98 fps, the 256 frames within a FF file should maintain that accuracy (so, I don't think we need to timestamp each frame). I haven't looked but I assume the config fps is used to calculate intra FF ts? If so, should we consider changing the config fps to 24.98, or leave it... we are talking about 0.4ms over 256 frames...

[g7gpr]

There are many places in RMS where small factors have been included and corrected for. I think we should find a way to include your findings.

---

From: Luc Busquin @.> Sent: Friday, February 16, 2024 3:11 AM To: CroatianMeteorNetwork/RMS @.> Cc: David Rollinson @.>; Mention @.> Subject: Re: [CroatianMeteorNetwork/RMS] Plot, score, and log timestamp intervals for analysis (PR #260)

Here's where I'm at with the frame rate. Even in PAL, the actual fps is ~24.982, and each frame is very evenly spaced with no significant variations (there may be some tiny variation over long periods.)

Unfortunately, the rtspsrc element is expecting exactly 25 fps, and is always attempting to go back to 25 fps. This causes the slight dips when the error reaches about 1 ms and the pts algorithm more or less smoothly adjust the pts to zero the error. It does this in a ~27s cycle with an amplitude of ~3ms. I don't see an easy way to tell the first element of the pipeline to expect 24.982 fps. It might be "easier" to write a pts smoothing algorithm in python if we want sub ms precision.

For the FF files, the first frame timestamp should be accurate to ~10ms (given the start time uncertainty and the pts wandering). Assuming 24.98 fps, the 256 frames within a FF file should maintain that accuracy (so, I don't think we need to timestamp each frame). I haven't looked but I assume the config fps is used to calculate intra FF ts? If so, should we consider changing the config fps to 24.98, or leave it... we are talking about 0.4ms over 256 frames...

— Reply to this email directly, view it on GitHubhttps://github.com/CroatianMeteorNetwork/RMS/pull/260#issuecomment-1947014599, or unsubscribehttps://github.com/notifications/unsubscribe-auth/ASMOVH4OGDGC4V3TYZHPREDYTZMWLAVCNFSM6AAAAABCSIV2CWVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTSNBXGAYTINJZHE. You are receiving this because you were mentioned.Message ID: @.***>

[dvida]

I'm seeing this on one Pi3 camera, does anyone else see something similar? I can share the data files via email. These are produced automatically during normal processing.