Timestamps of messages

[dg9bja]

Hi!

I use gr-iridium and that toolkit for some time now and it runs very stable.
How are the timestamps of that acars messages generated?

In that screenshot you see my system time by date command and a tail -f at my log file. The message at 09:13 is almost 5 minutes behind system time. When I restart iridium-extractor all is fine again. The longer it runs that more difference I get.

I am using a Pi 4 with PiOS 64. Installed it by using pybombs. SDR is a SDRPlay RSP1A.

[Sec42]

Putting an exact timestamp to an ACARS message is not really possible. An ACARS message is an SBD message. Those may be reassembled from up to around 4 LAPDm messages (see iridiumtk/reassembler/sbd.py). An LAPDm message may be reassembled from multiple IDA: packes.

That said, the timestamp printed by the acars module is (if I'm reading the code right) the timestamp of the last IDA fragment of the first SBD fragment that was reassembled into this message.

The timestamps will usually be within a few seconds from the sending time.

All this info however doesn't really pertain to your problem.

These timestamps itself are tracked from the start time by counting received samples on your SDR. If they are

One possibility is, that you are loosing samples, and thus the time tracking is off.

Another possibility is, that your "live" setup is CPU bound and/or buffering and actually just slow in processing messages.

You will need some further debugging to pinpoint the root cause.

For example, the output of iridium-parser contains timestamps sent from the satellites in IBC lines. If the difference of that timestamp to you system time is changing, your trouble is on the SDR side. If that time difference is (more or less) constant, the problem lies in your processing pipeline.

[dg9bja]

Okay thank you, that counting time from start time is my problem. Sometimes I am loosing samples. Then I should restart my process from time to time.
That confirm my what I already guessed.

[schneider42]

(I prepared this text some time ago, so it contains some redundant information)
Hi,

most likely these timestamps are directly created from the timestamps that gr-iridium assigned to the individual Iridium frames (I believe an ACARS message can be made up of several Iridium frames).

gr-iridium accounts for time like this:

• Get an absolute time when launching iridium-extractor.
• If the SDR supports getting time from GPS, get the time from GPS.
• If the SDR supports a pulse per second input, synchronize to the next pulse.
• Count samples received and increment the timestamp based on the number of samples seen.
• If the SDR supports meta data, update the sample count as indicate by the SDR.

Naturally this counting will drift away from your hosts wall clock over time. The reasons are:

1. The clock on your host is not perfect.
2. The sample rate of the SDR is not perfect. Different SDRs have different accuracy (the RSP1A specifies 0.5 ppm).
3. Samples lost between the SDR and the host if the SDR does not support meta data.

I don't know for how long you have been running your setup, but my guess is that number 3 is to blame here. Some SDR libraries let the user know if there are overflows, indicating lost samples on the command line. Not sure how the RSP1A can signal this condition, if it can.

[wiedehopf]

Would it be possible to warn about the discrepancy to system time greater than say 100ms?

Or even better just get a new reference once such an offset is detected (similar to what is done at launch).
I've seen some code is based on time differences, but this jumping approach should keep that code working.

[Sec42]

In an ideal setup, gr-iridium does not use system time at all. It is used as a fallback on startup once if you don't have a gps. The rest of the time is done by counting samples received from your sdr. The timekeeping on such a system is precise on the order of fractions of milliseconds.

It is true that the sdr clock may be a bit off, but 0.5 PPM for a RSP1A would still be less than 1 second per day.

If you are loosing samples (thus throwing the timestamp off) it would be better (from my point of view) to debug & fix that issue, than to build workarounds in gr-iridium referencing the (not very precise) system time.

If you can't or don't want to fix your system issue and are only interested in vaguely correct timestamps, there would be a way to address that on the parsing side, i.e. in iridium-toolkit.

Iridium does send it's own time periodically in "IBC" packets. These have around 2-10ms of "jitter" due to signal travel time from the satellite, but for a rough correction as you want it, it would be enough.

If that's the route you want to go, maybe open an feature request on the iridium-toolkit. I'll see if I can find the time for it :)

If possible, please run the reassembler with "-m ppm" on a recording of at least an hour, and attach the output.

[wiedehopf]

The fallback is already referencing system time so checking against it shouldn't reduce precision.
Not checking against it means that lost samples result in completely bad timestamps and it's a mystery to a user where the bad timestamps come from. (if they are even noticed at all)
I don't see why guarding against that scenario is a bad thing.
But i don't think i understand the code well enough for a PR.

Thank you for offering to help with system issues, pretty sure they're fixed.
This was more about the general pitfall for users and preventing completely bad timestamps when getting lost samples.

[Sec42]

gr-iridium already has code to output a warning that your setup is loosing samples. Maybe that warning could be more clear that your system has issues that should be fixed, and timestamps will be wrong if you continue anyway.

I personally think if you really want to do some workaround for a broken setup it would be more sensible to try to do time correction with the help of received IBC timestamps via code in iridium-toolkit.

[rpatel3001]

occasionally losing samples is not necessarily a broken setup. Even if I only rarely lose a few samples (I'm seeing a message about 2% loss every 5-10 minutes), it adds up when the software is running for long periods of time. I think that small level of lost samples probably can't be avoided with high bandwidth SDRs. Time loss from a PPM offset can also add up when running a permanent feeder station.

[schneider42]

I believe implementing some kind of dynamic re-synchronization with system time is not a super trivial task.

Two things which come to mind:

• We absolutely do not want to trigger a re-sync if there were no samples lost. I currently do not trust the detection algorithm for that enough. I'm pretty sure I've seen the message already on systems where everything is fine and just some buffering on USB / driver side causes the message to print. That was on an embedded system, but makes me worry.
• What happens if the SDR has a slight forward drift (clock going to fast), while the system has a slight backwards drift (clock going to slow). If enough time time passes before some samples are lost, gr-iridium will have output timestamps which are far enough in the "future" that a reset back to system time starts generating timestamps which have already been produced. We put a lot of effort to make sure that gr-iridium always outputs monotonically increasing timestamps. Maybe you have a proposal what to do in this case?

Please also consider Sec's proposal to track Iridium network time (as available in IBC packets) that allow you to have a completely independent time source which does neither rely on samples, nor the system time.