iMet-4 decoding is getting a fast EOF

[bismurphy]

Hi!

A station near me has begun launching iMet-4 sondes, which I've never received before. I've received plenty of DFM-17's in the past. I saw a sonde with ID B8A358DC in the air and attempted to receive.

What I saw in the web interface, and the terminal, was that repeatedly I would get a sonde detected, then "SDR #0 has been allocated to Decoder (IMET, 403.998 MHZ)". Then "Starting decoder subprocess", followed 1 second later by "Closed decoder subprocess". Every single frequency scan would find this sonde, then we would get the decoder, which immediately kicked out, with no packets decoded. I never decoded anything from this sonde.

I added a few extra statements to decode.py to attempt to determine what conditions are failing, particularly starting at https://github.com/projecthorus/radiosonde_auto_rx/blob/938cc6d17d3563c155bead009f3f357532cf8537/auto_rx/autorx/decode.py#L1125

Particularly, I added a self.log_info('Into While loop') immediately after the main while statement, and then a similar line after the for _line in self.async_reader.readlines():. Finally, at the end of the while loop, I added self.log_info(str(self.async_reader.eof())) to double-check that this condition is what caused the while-loop to exit.

What I found is that, like clockwork, the While loop ran 10 times, and that the for-loop never ran at all (meaning self.async_reader.readlines() was always empty). The final statement returned False on all runs, except the last one, which was True, indicating that indeed the eof condition was what caused the loop to exit.

From there, I'm not sure how to continue hunting the source of this behavior. It's possible that iMet-4 sondes are hard to decode or something, I'm not sure, but the fact that other stations seem to have received this sonde successfully, and that I had a very strong SNR, would suggest that my station should be able to decode this.

Now that this sonde's flight has concluded, I won't be able to do further checks on this one, but if there are any particular extra debug lines I should add for the next time one of these is in flight, let me know.

[darksidelemm]

That the decoder dies immediately indicates the decoder has crashed for some reason.

You could try starting up a decoder manually using the command:

python3 auto_rx.py -f 404.0 -m IMET -v

It would be interesting to see if the decoder crashes even with no signal present. It should just sit there for a while until it times out with no packets.

Using -v will also give the command line that is run. Running this externally to auto_rx may give some information as to what is breaking.

[darksidelemm]

I just had a go running up an imet decoder on the latest testing branch with an iMet-4 test sonde I have on hand, and that seems to work OK.

I did initially get an error regarding the decoder versions, but this was because I hadn't re-built the decoders since changing the auto_rx version number:

2023-01-21 08:54:59,555 CRITICAL:Decoder (RTLSDR 0) IMET 402.000 - Decoder version (1.6.0-beta24) does not match auto_rx version (1.6.0-beta25). Have you re-built the decoders? (./build.sh)

Otherwise, it spun up a decoder and was decoding telemetry fine.

[rs1729]

On Windows systems it is sometimes (depends on the compiler I guess) necessary to set the binary mode. However auto_rx runs on linux, it is always binary mode. And you would have similar issues with the other decoders.

You can try to record the iMet4 signal and then decode the recording. If your decoder exits immediately, you could upload the recording for testing.

EDIT: Next time the imet-decoder exits (e.g. on IMET, 403.998 MHZ, look for the detected frequency), stop auto_rx and open a terminal and run for 10 seconds

rtl_fm -M raw -f 403998k -s 48k imet4_403998kHz_IQ.raw

add ppm offset (-p <ppm>) and/or bias-T (-T) options if needed. Now take the decoder (imet4iq)

./imet4iq -r --iq 0.0 - 48000 16 imet4_403998kHz_IQ.raw

and look if there is any output. If not, for a 10 sec recording it might be difficult to tell if it ran through the file or exited prematurely. So you could also test

rtl_fm -M raw -f 403998k -s 48k | tee imet4_403998kHz_IQ.raw | ./imet4iq -r --iq 0.0 - 48000 16

and see if it stops and how much it recorded. As @darksidelemm said, it is possible you have the issue even if there is no iMet signal, just noise.

[bismurphy]

@rs1729 Where might I find the imet4iq executable? From the root radiosonde_auto_rx directory a find . -name "imet4iq" doesn't turn anything up.

Today another iMet went up, this time showing on Sondehub as 402.998. I ran python3 auto_rx.py -f 404.0 -m IMET -v and got a repeating output that looked like this:

https://pastebin.com/GQ5eY48A

I'm not sure what the lsusb parsing error is - when I run a standard lsusb in a different terminal I don't see any of those UNAVAILABLE errors. But I also doubt it has anything to do with the decoder.

[rs1729]

I was assuming you were using the latest beta/test branch, but (1.6.0-beta24) was @darksidelemm 's comment. The older version was called imet1rs_dft, I see it in your log output. This version decodes the FM audio from rtl_fm. The new version in the test branch uses IQ data from rtl_fm, if I remember correctly.

(Did you run auto_rx on 404 MHz or 403 MHz as detected?)

I think there is a debug/recording option in the main branch as well, recording FM audio in this case.

Or you close auto_rx after dectection of imet4, and take the "Decoder Command" and record the signal that was detected. E.g. if

2023-01-23 10:12:43,061 DEBUG:Decoder #0 IMET 402.999 - Decoder Command: rtl_fm -p 0 -d 0 -M fm -F9 -s 15k -f 402999000 2>/dev/null |sox -t raw -r 15k -e s -b 16 -c 1 - -r 48000 -b 8 -t wav - highpass 20 2>/dev/null |./imet1rs_dft --json  2>/dev/null

exit auto_rx and open a terminal, go to a working directory and copy imet1rs_dft, then

rtl_fm -p 0 -d 0 -M fm -F9 -s 15k -f 402999000 | sox -t raw -r 15k -e s -b 16 -c 1 - -r 48000 -b 8 -t wav - highpass 20 2>/dev/null | tee imet4_402999kHz_FM.wav | ./imet1rs_dft

If you don' get any decoder output and it exits immediately, you can upload the recorded imet4_402999kHz_FM.wav for inspection. Maybe you get rtl_fm error messages (I removed the "2>/dev/null")

Not sure about the lsusb error and if there is an issue with the rtl-sdr device. I'm not so familiar with the decoding chain, but I assume if there would not be a free rtl-sdr available, auto_rx would not try to start decoding. And you don't have these problems with DFM-17 radiosondes, right?

You can always try the latest beta, maybe there are other bugfixes.

Now I see there was a similar issue https://github.com/projecthorus/radiosonde_auto_rx/issues/616 The iMet-4 is one of a few where FM audio was used for the decoder, and sox was used for generating a wav header. Most of the other decoders take IQ data, the wav header is not needed if the parameters a set or the fsk_demod output is used.

Don't know how much sox is used in the main release and if it is needed in the latest beta. Ca you check if sox is available on your system?

EDIT: Not sure, if the FM-mode (and sox) would also be used in scan/detect in the September release? Seems like IMET was detected in https://github.com/projecthorus/radiosonde_auto_rx/issues/616 without sox. So checking for sox would be the first thing to do.

[bismurphy]

That did it! A simple sudo apt install sox solves everything and I can now receive the iMet sondes perfectly. Thank you for your help!

I seem to have missed the proper dependency-installation step in the instructions; thank you for pointing me in the right direction.