dvbs_tx_rx example frozen DVB-S2 PL Sync

[wbenoot]

Hey,

I am experimenting with your example flow graphs in the gnuradio companion. Since the example .ts file download link is broken (for me anyway), I created my own one by calculating the required TS bitrate for the given settings (QPSK, 0.20 rolloff, 1/4 code rate, pilots on at a 1 MBaud/s rate): https://www.satbroadcasts.com/DVB-S_Bitrate_and_Bandwidth_Calculator.html

and then using ffmpeg to convert a random mp4 video to an MPEG TS file ffmpeg -i input.mp4 -c:v copy -b:v 0.4795M -c:a copy output.ts

When I run the example in grc the output of pl_sync_out is completely frozen (after half a second) and stuck on the following:

I'd expect the constellation diagram to converge to a noisy QPSK modulation scheme, however it seems that it instantly stops. I don't get any error anywhere. Am I doing something wrong?

[wbenoot]

Maybe it is worth note that sometimes when it freezes the following warning message does pop-up:

bbdeheader_bb :warning: Baseband header invalid (dfl not a multiple of 8).
bbdeheader_bb :warning: Baseband header invalid (dfl > kbch - 80).

[igorauad]

Hi @wbenoot ,

So:

• I've double-checked the dvbs2_tx_rx.grc flowgraph here. Left it running for some minutes. I don't have the problem you are mentioning. Are you sure your TS file is large enough? I wonder if that could cause any problems. In any case, the file source block is set to repeat the input file in this example.
• The link to the example TS file should be ok. It's on @drmpeg's home page. https://www.w6rz.net/thefuryclip.ts
• The bbdeheader warnings are normal. They typically happen when the BCH decoder fails to correct the errors on a given codeword. The message is not dropped by the BCH decoder block. Instead, it goes to the upper layers. Then, when the bbdeheader block parses the BBHEADER, it does some sanity checks like this. It drops the BBFRAME in case they fail.
• Could you try running the apps directly? If you don't have a TS file to test, I'd recommend running tsp. Like so:

tsp -I craft --pid 100 | dvbs2-tx --pilots | dvbs2-rx --log --sink file --out-file /dev/null --pilots on --gui

To install tsp on Ubuntu:

add-apt-repository ppa:blockstream/satellite
apt-get update
apt-get install tsduck

[wbenoot]

The video I use is big enough, doubled checked by using a longer one and trying the video you provided. Unfortunately it still freezes.

I did notice that I am unable to execute the full application, I get the following error when calling the application:

Traceback (most recent call last):
  File "/Users/wbenoot/anaconda3/envs/gnu_radio/bin/dvbs2-tx", line 1073, in <module>
    main()
  File "/Users/wbenoot/anaconda3/envs/gnu_radio/bin/dvbs2-tx", line 1026, in main
    options = argument_parser()
              ^^^^^^^^^^^^^^^^^
  File "/Users/wbenoot/anaconda3/envs/gnu_radio/bin/dvbs2-tx", line 782, in argument_parser
    version=parse_version())
            ^^^^^^^^^^^^^^^
  File "/Users/wbenoot/anaconda3/envs/gnu_radio/bin/dvbs2-tx", line 46, in parse_version
    ldd_out = subprocess.check_output(['ldd', cpython_lib]).decode()
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/wbenoot/anaconda3/envs/gnu_radio/lib/python3.11/subprocess.py", line 466, in check_output
    return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/wbenoot/anaconda3/envs/gnu_radio/lib/python3.11/subprocess.py", line 548, in run
    with Popen(*popenargs, **kwargs) as process:
         ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/wbenoot/anaconda3/envs/gnu_radio/lib/python3.11/subprocess.py", line 1026, in __init__
    self._execute_child(args, executable, preexec_fn, close_fds,
  File "/Users/wbenoot/anaconda3/envs/gnu_radio/lib/python3.11/subprocess.py", line 1950, in _execute_child
    raise child_exception_type(errno_num, err_msg, err_filename)
FileNotFoundError: [Errno 2] No such file or directory: 'ldd'

I installed gnuradio through anaconda as this was the most accessible to me. I installed the extension by following this tutorial for OOT-modules with Conda-installed gnuradio. Since I can correctly import all the blocks in my grc when running it from within the environment I assume everything works on that part, but I cannot be sure that this is not the cause.

[wbenoot]

'ldd' is not supported on Mac apparently, I'll have a look on how to fix that

[wbenoot]

changing the line in both dvbs2-rx.py and dvbs2-tx.py from

ldd_out = subprocess.check_output(['ldd', cpython_lib]).decode()

to

ldd_out = subprocess.check_output(['otool', '-L', cpython_lib]).decode()

makes it work on MacOS (at least the invoking applications). I see the same thing happening here, after some time it just freezes (the Symbol Sync Output and PL sync output always stay a circle, but for the first x-seconds they do update):

The log is the following:

(gnu_radio) wbenoot@MBP Downloads dvbs2-tx --source file --in-file thefuryclip.ts | dvbs2-rx --log --sink file --out-file /dev/null --gui
log :info: Starting DVB-S2 Rx
log :info: Lock=False
bbdeheader_bb :warning: Baseband header invalid (dfl > kbch - 80).
bbdeheader_bb :warning: Baseband header invalid (dfl > kbch - 80).
log :info: Lock=True; SNR=1.87; FECFRAMEs=224; FER=8.7e-01; TS Packets=317; PER=0.0e+00
log :info: Lock=True; SNR=1.93; FECFRAMEs=491; FER=9.4e-01; TS Packets=317; PER=0.0e+00
log :info: Lock=True; SNR=1.90; FECFRAMEs=736; FER=9.6e-01; TS Packets=317; PER=0.0e+00
bbdeheader_bb :warning: Baseband header invalid (dfl not a multiple of 8).
bbdeheader_bb :warning: Baseband header invalid (dfl > kbch - 80).
log :info: Lock=True; SNR=1.89; FECFRAMEs=992; FER=9.7e-01; TS Packets=317; PER=0.0e+00
bbdeheader_bb :warning: Baseband header invalid (syncd > dfl).
log :info: Lock=True; SNR=1.85; FECFRAMEs=1274; FER=9.8e-01; TS Packets=317; PER=0.0e+00
log :info: Lock=True; SNR=1.91; FECFRAMEs=1536; FER=9.8e-01; TS Packets=317; PER=0.0e+00
bbdeheader_bb :warning: Baseband header invalid (dfl > kbch - 80).
log :info: Lock=True; SNR=1.87; FECFRAMEs=1797; FER=9.8e-01; TS Packets=317; PER=0.0e+00
bbdeheader_bb :warning: Baseband header unsupported (upl != 188 bytes).
log :info: Lock=True; SNR=1.84; FECFRAMEs=2078; FER=9.9e-01; TS Packets=317; PER=0.0e+00
bbdeheader_bb :warning: Baseband header invalid (dfl not a multiple of 8).
log :info: Lock=True; SNR=1.83; FECFRAMEs=2336; FER=9.9e-01; TS Packets=317; PER=0.0e+00
log :info: Lock=True; SNR=1.93; FECFRAMEs=2597; FER=9.9e-01; TS Packets=317; PER=0.0e+00
bbdeheader_bb :warning: Baseband header invalid (dfl not a multiple of 8).
log :info: Lock=True; SNR=1.92; FECFRAMEs=2868; FER=9.9e-01; TS Packets=317; PER=0.0e+00
bbdeheader_bb :warning: Baseband header invalid (dfl > kbch - 80).
bbdeheader_bb :warning: Baseband header invalid (dfl > kbch - 80).
bbdeheader_bb :warning: Baseband header unsupported (upl != 188 bytes).
log :info: Lock=True; SNR=1.89; FECFRAMEs=3136; FER=9.9e-01; TS Packets=317; PER=0.0e+00
log :info: Lock=True; SNR=1.92; FECFRAMEs=3392; FER=9.9e-01; TS Packets=317; PER=0.0e+00
log :info: Lock=True; SNR=1.88; FECFRAMEs=3616; FER=9.9e-01; TS Packets=317; PER=0.0e+00
log :info: Lock=True; SNR=1.88; FECFRAMEs=3616; FER=9.9e-01; TS Packets=317; PER=0.0e+00
log :info: Lock=True; SNR=1.88; FECFRAMEs=3616; FER=9.9e-01; TS Packets=317; PER=0.0e+00
log :info: Lock=True; SNR=1.88; FECFRAMEs=3616; FER=9.9e-01; TS Packets=317; PER=0.0e+00
log :info: Lock=True; SNR=1.88; FECFRAMEs=3616; FER=9.9e-01; TS Packets=317; PER=0.0e+00
log :info: Lock=True; SNR=1.88; FECFRAMEs=3616; FER=9.9e-01; TS Packets=317; PER=0.0e+00
log :info: Lock=True; SNR=1.88; FECFRAMEs=3616; FER=9.9e-01; TS Packets=317; PER=0.0e+00
log :info: Lock=True; SNR=1.88; FECFRAMEs=3616; FER=9.9e-01; TS Packets=317; PER=0.0e+00
log :info: Lock=True; SNR=1.88; FECFRAMEs=3616; FER=9.9e-01; TS Packets=317; PER=0.0e+00
log :info: Lock=True; SNR=1.88; FECFRAMEs=3616; FER=9.9e-01; TS Packets=317; PER=0.0e+00
log :info: Lock=True; SNR=1.88; FECFRAMEs=3616; FER=9.9e-01; TS Packets=317; PER=0.0e+00
log :info: Lock=True; SNR=1.88; FECFRAMEs=3616; FER=9.9e-01; TS Packets=317; PER=0.0e+00
... This continues 

[igorauad]

@wbenoot Personally, I have never tried building the project on macOS. I use macOS, but I do everything related to GNU Radio inside Docker containers. See, e.g.:

• https://github.com/igorauad/gr-dvbs2rx/blob/master/docs/installation.md#docker-image.
• https://hub.docker.com/r/igorfreire/gnuradio-oot-dev.

As for the ldd error, thanks for reporting it. I have pushed a patch in e82f3ec. However, I think otool has a different output for the library versions, so I need to adapt the parsing. Could you share the output subprocess.check_output(['otool', '-L', cpython_lib]).decode() so that the function correctly captures the library version?

Regarding the freezing, I should note that, unlike the dvbs2_tx_rx example flowgraph, the dvbs2-tx application does not repeat the input by default. For that, you would need to use the --in-repeat option. So change your command to:

dvbs2-tx --source file --in-file thefuryclip.ts --in-repeat | dvbs2-rx --log --sink file --out-file /dev/null --gui

If it still freezes after that, I think you would need to build the project in Debug mode and run dvbs2-rx on gdb to see where it is freezing.

[wbenoot]

This is the output of the otool version (of dvbs2-rx app):

/Users/wbenoot/anaconda3/envs/gnuradio/lib/python3.11/site-packages/gnuradio/dvbs2rx/dvbs2rx_python.cpython-311-darwin.so:
    /Users/wbenoot/anaconda3/envs/gnuradio/lib/libgnuradio-dvbs2rx.1.2.0.dylib (compatibility version 1.2.0, current version 1.2.0)
    @rpath/libgnuradio-runtime.3.10.6.dylib (compatibility version 3.10.6, current version 3.10.6)
    /usr/lib/libSystem.B.dylib (compatibility version 1.0.0, current version 1319.100.3)
    @rpath/libc++.1.dylib (compatibility version 1.0.0, current version 1.0.0)

The freezing of the app was indeed due to the --in-repeat, however the frequency correction is still not happening. For a reference, I built the repo on a Ubuntu Desktop that I have laying around. I again used anaconda to install everything, and on this machine the frequency is corrected and a correct QPSK is shown. On my Mac the same execution just shows an ever rotating modulation scheme, not correcting frequency.

I'll build it in debug mode and see if there is anything obvious. I don't use docker since the normal gnuradio worked well on my native anaconda installation, but I might switch to docker or a VM if I can't directly find the problem.

[igorauad]

Thanks, @wbenoot . Updated the version parsing in 13faa94.

Regarding the frequency correction, could you please add -d3 to your dvbs2-rx command and share the logs? With this debugging level, the application will print lots of logs. So perhaps save them on a file.

[wbenoot]

The command: dvbs2-tx --pilots --source file --in-file thefuryclip.ts --in-repeat | dvbs2-rx --log-all --pilots on --sink file --out-file /dev/null --gui -d3

The log is the following:

log :info: Starting DVB-S2 Rx
log :info: {"lock": false, "snr": null, "plsync": {"coarse_freq_corr": false, "freq_offset_hz": 0.0, "frame_count": {"processed": 0, "rejected": 0, "dummy": 0}, "locked_since": null}, "fec": {"frames": 0, "errors": 0, "fer": null, "avg_ldpc_trials": null}, "mpeg-ts": {"packets": 0, "per": null}}
bbdeheader_bb :warning: Baseband header unsupported (upl != 188 bytes).
log :info: {"lock": true, "snr": 1.8731777667999268, "plsync": {"coarse_freq_corr": true, "freq_offset_hz": -677.571864798665, "frame_count": {"processed": 237, "rejected": 0, "dummy": 0}, "locked_since": "2023-07-10T16:01:14.338511"}, "fec": {"frames": 206, "errors": 176, "fer": 0.8543689320388349, "avg_ldpc_trials": 25}, "mpeg-ts": {"packets": 317, "per": 0.0}}
bbdeheader_bb :warning: Baseband header invalid (dfl > kbch - 80).
log :info: {"lock": true, "snr": 1.8886858224868774, "plsync": {"coarse_freq_corr": true, "freq_offset_hz": -677.572563290596, "frame_count": {"processed": 480, "rejected": 0, "dummy": 0}, "locked_since": "2023-07-10T16:01:14.338511"}, "fec": {"frames": 448, "errors": 418, "fer": 0.9330357142857143, "avg_ldpc_trials": 25}, "mpeg-ts": {"packets": 317, "per": 0.0}}
bbdeheader_bb :warning: Baseband header invalid (dfl not a multiple of 8).
log :info: {"lock": true, "snr": 1.8290290832519531, "plsync": {"coarse_freq_corr": true, "freq_offset_hz": -677.5704678148031, "frame_count": {"processed": 746, "rejected": 0, "dummy": 0}, "locked_since": "2023-07-10T16:01:14.338511"}, "fec": {"frames": 713, "errors": 683, "fer": 0.9579242636746143, "avg_ldpc_trials": 25}, "mpeg-ts": {"packets": 317, "per": 0.0}}
log :info: {"lock": true, "snr": 1.8647611141204834, "plsync": {"coarse_freq_corr": true, "freq_offset_hz": -677.5728543289006, "frame_count": {"processed": 992, "rejected": 0, "dummy": 0}, "locked_since": "2023-07-10T16:01:14.338511"}, "fec": {"frames": 960, "errors": 930, "fer": 0.96875, "avg_ldpc_trials": 25}, "mpeg-ts": {"packets": 317, "per": 0.0}}
log :info: {"lock": true, "snr": 1.8546735048294067, "plsync": {"coarse_freq_corr": true, "freq_offset_hz": -677.5738438591361, "frame_count": {"processed": 1237, "rejected": 0, "dummy": 0}, "locked_since": "2023-07-10T16:01:14.338511"}, "fec": {"frames": 1206, "errors": 1176, "fer": 0.9751243781094527, "avg_ldpc_trials": 25}, "mpeg-ts": {"packets": 317, "per": 0.0}}
bbdeheader_bb :warning: Baseband header invalid (dfl not a multiple of 8).
log :info: {"lock": true, "snr": 1.870958685874939, "plsync": {"coarse_freq_corr": true, "freq_offset_hz": -677.5734946131706, "frame_count": {"processed": 1462, "rejected": 0, "dummy": 0}, "locked_since": "2023-07-10T16:01:14.338511"}, "fec": {"frames": 1432, "errors": 1402, "fer": 0.979050279329609, "avg_ldpc_trials": 25}, "mpeg-ts": {"packets": 317, "per": 0.0}}
bbdeheader_bb :warning: Baseband header invalid (dfl > kbch - 80).
log :info: {"lock": true, "snr": 1.8956810235977173, "plsync": {"coarse_freq_corr": true, "freq_offset_hz": -677.5775109417737, "frame_count": {"processed": 1632, "rejected": 0, "dummy": 0}, "locked_since": "2023-07-10T16:01:14.338511"}, "fec": {"frames": 1600, "errors": 1570, "fer": 0.98125, "avg_ldpc_trials": 25}, "mpeg-ts": {"packets": 317, "per": 0.0}}
bbdeheader_bb :warning: Baseband header invalid (dfl > kbch - 80).
log :info: {"lock": true, "snr": 1.898589015007019, "plsync": {"coarse_freq_corr": true, "freq_offset_hz": -677.574600558728, "frame_count": {"processed": 1862, "rejected": 0, "dummy": 0}, "locked_since": "2023-07-10T16:01:14.338511"}, "fec": {"frames": 1831, "errors": 1801, "fer": 0.983615510649918, "avg_ldpc_trials": 25}, "mpeg-ts": {"packets": 317, "per": 0.0}}
...

With the following gui output:

Should there be more output than this?

[wbenoot]

The same command on my Linux machine: dvbs2-tx --pilots --source file --in-file thefuryclip.ts --in-repeat | dvbs2-rx --log-all --pilots on --sink file --out-file /dev/null --gui -d3

Gives:

log :info: Starting DVB-S2 Rx
log :info: {"lock": false, "snr": null, "plsync": {"coarse_freq_corr": false, "freq_offset_hz": 0.0, "frame_count": {"processed": 0, "rejected": 0, "dummy": 0}, "locked_since": null}, "fec": {"frames": 0, "errors": 0, "fer": null, "avg_ldpc_trials": null}, "mpeg-ts": {"packets": 0, "per": null}}
log :info: {"lock": true, "snr": 26.21786117553711, "plsync": {"coarse_freq_corr": true, "freq_offset_hz": 0.0091481480168909, "frame_count": {"processed": 254, "rejected": 0, "dummy": 0}, "locked_since": "2023-07-11T09:23:37.948777"}, "fec": {"frames": 224, "errors": 0, "fer": 0.0, "avg_ldpc_trials": 0}, "mpeg-ts": {"packets": 2371, "per": 0.0}}
log :info: {"lock": true, "snr": 26.24445152282715, "plsync": {"coarse_freq_corr": true, "freq_offset_hz": 0.005774516864676116, "frame_count": {"processed": 501, "rejected": 0, "dummy": 0}, "locked_since": "2023-07-11T09:23:37.948777"}, "fec": {"frames": 480, "errors": 0, "fer": 0.0, "avg_ldpc_trials": 0}, "mpeg-ts": {"packets": 5082, "per": 0.0}}
log :info: {"lock": true, "snr": 26.248666763305664, "plsync": {"coarse_freq_corr": true, "freq_offset_hz": 0.003584923913280136, "frame_count": {"processed": 748, "rejected": 0, "dummy": 0}, "locked_since": "2023-07-11T09:23:37.948777"}, "fec": {"frames": 736, "errors": 0, "fer": 0.0, "avg_ldpc_trials": 0}, "mpeg-ts": {"packets": 7794, "per": 0.0}}
log :info: {"lock": true, "snr": 26.21834945678711, "plsync": {"coarse_freq_corr": true, "freq_offset_hz": 0.003956820204820133, "frame_count": {"processed": 993, "rejected": 0, "dummy": 0}, "locked_since": "2023-07-11T09:23:37.948777"}, "fec": {"frames": 961, "errors": 0, "fer": 0.0, "avg_ldpc_trials": 0}, "mpeg-ts": {"packets": 10166, "per": 0.0}}
log :info: {"lock": true, "snr": 26.25749397277832, "plsync": {"coarse_freq_corr": true, "freq_offset_hz": 0.006289267329151471, "frame_count": {"processed": 1248, "rejected": 0, "dummy": 0}, "locked_since": "2023-07-11T09:23:37.948777"}, "fec": {"frames": 1216, "errors": 0, "fer": 0.0, "avg_ldpc_trials": 0}, "mpeg-ts": {"packets": 12877, "per": 0.0}}
log :info: {"lock": true, "snr": 26.210033416748047, "plsync": {"coarse_freq_corr": true, "freq_offset_hz": -0.0004802044872853628, "frame_count": {"processed": 1504, "rejected": 0, "dummy": 0}, "locked_since": "2023-07-11T09:23:37.948777"}, "fec": {"frames": 1472, "errors": 0, "fer": 0.0, "avg_ldpc_trials": 0}, "mpeg-ts": {"packets": 15588, "per": 0.0}}
log :info: {"lock": true, "snr": 26.282787322998047, "plsync": {"coarse_freq_corr": true, "freq_offset_hz": 0.004657370045180187, "frame_count": {"processed": 1749, "rejected": 0, "dummy": 0}, "locked_since": "2023-07-11T09:23:37.948777"}, "fec": {"frames": 1728, "errors": 0, "fer": 0.0, "avg_ldpc_trials": 0}, "mpeg-ts": {"packets": 18299, "per": 0.0}}
...

With the following output GUI:

[igorauad]

Thanks for reporting, @wbenoot . I don't have much time to investigate this today, but I will do that soon. From a quick look, I see that your macOS experiment logs a very low SNR, which is unexpected. Your Linux experiment logs an SNR of around 26 dB, which is expected.

I will test this on macOS myself as soon as I find a chance. Also, I'm working on setting up a CI job to build and test on macOS.

In the meantime, you could also try saving the Tx IQ into a file. Then, could you run the Rx application reading from the file? That is, first, run:

dvbs2-tx --pilots --source file --in-file thefuryclip.ts --in-repeat --sink file --out-file /tmp/test.iq

Let it record IQ samples for some time, then stop.

Next, run the Rx:

dvbs2-rx --log-all --pilots on --source file --in-file /tmp/test.iq --sink file --out-file /dev/null --gui -d3

This could make a difference because sometimes the Tx application pipes unexpected stuff (e.g., error/warning logs) into the Rx application. A single unexpected log could be enough to break the IQ format, especially with the default IQ format based on fc32 (which, by the way, you could change with --out-iq-format and --in-iq-format on Tx and Rx, respectively). I have been careful to avoid the Tx application printing logs to stdout, as they would prevent piping the output into Rx. However, I'd like to know if that could not work as intended on macOS. Maybe there is a warning there.

[igorauad]

@wbenoot, apologies for the long delay. It took me quite some time to get back to the project.

I have pushed some fixes to build and test on macOS. Also, I have adapted the CI workflow to build and test on macOS (in addition to Ubuntu and Fedora). See, for instance, this job: 18008551069 . The changes are already in the master branch.

As for the test you mentioned, I have tested the same command and got it working as expected.

Command (same as you used):

dvbs2-tx --pilots --source file --in-file thefuryclip.ts --in-repeat | dvbs2-rx --log-all --pilots on --sink file --out-file /dev/null --gui -d3

Screenshot:

[igorauad]

@wbenoot I'm cleaning up old pending issues in the repository. If you still have a problem, please don't hesitate to reopen it.

Thanks