Move from Debian to Pi - strange waterfall pattern

Hi all.

Been running station #702 on Debian for just over 2 years. But for no known reason, it became unstable requiring stop/staring of Satnogs service every month or so. (Waterfalls were fine, it just would randomly stop providing waterfalls).

Decided to put it on a fresh Pi 4 hardware and software.
Out of the gate, getting a very odd looking waterfall on every decode:

Every sat since changing PCs results in the exact same pattern.
Never seen anything like it. Same antenna, same coax, same RTLSDRv3, same USB cable.
Just unplugged from Debian, moved USB about 4-5 inches and plugged into new Pi 4.

Here is my support dump:

------------[ copy here ]------------
    {
        "versions": {
            "satnogs-client": "1.5.1",
            "satnogs-client-ansible": "202105301943",
            "satnogs-flowgraphs": "1.3.1-1",
            "gr-satnogs": "2.2.0.0-1",
            "gr-soapy": "2.1.3-1",
            "gnuradio": "3.8.2.0-2",
            "satnogs-config": "0.12"
        },
        "state": {
            "is-applied": true,
            "pending-tags": null
        },
        "system": {
            "date": "2021-07-18T19:35:00.945453+00:00",
            "distribution": {
                "DESCRIPTION": "Raspbian GNU/Linux 10 (buster)",
                "RELEASE": "10",
                "CODENAME": "buster",
                "ID": "Raspbian"
            },
            "pending-updates": true,
            "platform": {
                "system": "Linux",
                "node": "satnogs-uhf-702",
                "release": "5.10.17-v7l+",
                "version": "#1421 SMP Thu May 27 14:00:13 BST 2021",
                "machine": "armv7l",
                "processor": ""
            },
            "memory": {
                "total": 4064976896,
                "available": 3558785024,
                "percent": 12.5,
                "used": 338866176,
                "free": 2491727872,
                "active": 415137792,
                "inactive": 1008394240,
                "buffers": 145387520,
                "cached": 1088995328,
                "shared": 17326080,
                "slab": 114262016
            },
            "disk": {
                "total": 7366754304,
                "used": 4460929024,
                "free": 2552209408,
                "percent": 63.6
            }
        },
        "configuration": {
            "satnogs_antenna": "RX",
            "satnogs_api_token": "[redacted]",
            "satnogs_rf_gain": "20.7",
            "satnogs_rx_samp_rate": "2.048e6",
            "satnogs_soapy_rx_device": "driver=rtlsdr,serial=22",
            "satnogs_station_elev": "400",
            "satnogs_station_id": "702",
            "satnogs_station_lat": "33.49641",
            "satnogs_station_lon": "-117.089502"
        }
    }
    ------------[ copy end ]-------------

Same carefully tuned gain value etc.

Any suggestions what changed?

How are you powering your RPi?

I’ve seen this happening when the RTL-SDR is not fully initialized on observation start. Do you see anything strange in the logs files? Also, can you swap the RTL-SDR device with another one to make sure it’s not a hardware issue?

The Pi is powered from the official USB-C plug pack (the black one with the thick cable).

Looking at:
journalctl -f -u satnogs-client.service

Shows:

Jul 18 18:47:35 satnogs-uhf-702 systemd[1]: Started SatNOGS client.
Jul 18 18:54:05 satnogs-uhf-702 satnogs-client[27801]: rot_init called
Jul 18 18:54:05 satnogs-uhf-702 satnogs-client[27801]: dummy: _init called
Jul 18 18:54:05 satnogs-uhf-702 satnogs-client[27801]: rot_register (1)
Jul 18 18:54:05 satnogs-uhf-702 satnogs-client[27801]: rot_register (2)
Jul 18 18:54:05 satnogs-uhf-702 satnogs-client[27801]: dummy_rot_init called
Jul 18 18:54:05 satnogs-uhf-702 satnogs-client[27801]: rot_open called
Jul 18 18:54:05 satnogs-uhf-702 satnogs-client[27801]: dummy_rot_open called
Jul 18 18:54:05 satnogs-uhf-702 satnogs-client[27801]: rot_get_position called
Jul 18 18:54:05 satnogs-uhf-702 satnogs-client[27801]: dummy_rot_get_position called
Jul 18 18:54:05 satnogs-uhf-702 satnogs-client[27801]: rot_set_position called
Jul 18 18:54:07 satnogs-uhf-702 satnogs-client[27801]: usb_claim_interface error -6
Jul 18 18:54:07 satnogs-uhf-702 satnogs-client[27801]: Found Rafael Micro R820T tuner
Jul 18 18:54:07 satnogs-uhf-702 satnogs-client[27801]: [INFO] Opening Generic RTL2832U OEM :: 22...
Jul 18 18:54:07 satnogs-uhf-702 satnogs-client[27801]: Found Rafael Micro R820T tuner
Jul 18 18:54:08 satnogs-uhf-702 satnogs-client[27801]: [R82XX] PLL not locked!
Jul 18 18:54:08 satnogs-uhf-702 satnogs-client[27801]: [INFO] Using format CF32.
Jul 18 18:54:20 satnogs-uhf-702 satnogs-client[27801]: /var/lib/satnogs/.gnuradio/prefs/vmcircbuf_default_factory: No such file or directory
Jul 18 18:54:20 satnogs-uhf-702 satnogs-client[27801]: vmcircbuf_createfilemapping: createfilemapping is not available
Jul 18 18:54:20 satnogs-uhf-702 satnogs-client[27801]: gr::vmcircbuf_sysv_shm: shmat (2): Invalid argument
Jul 18 18:54:20 satnogs-uhf-702 satnogs-client[27801]: Allocating 15 zero-copy buffers
Jul 18 19:04:04 satnogs-uhf-702 satnogs-client[27801]: usb_claim_interface error -6
Jul 18 19:04:04 satnogs-uhf-702 satnogs-client[27801]: Found Rafael Micro R820T tuner
Jul 18 19:04:04 satnogs-uhf-702 satnogs-client[27801]: [INFO] Opening Generic RTL2832U OEM :: 22...
Jul 18 19:04:04 satnogs-uhf-702 satnogs-client[27801]: Found Rafael Micro R820T tuner
Jul 18 19:04:05 satnogs-uhf-702 satnogs-client[27801]: [R82XX] PLL not locked!
Jul 18 19:04:05 satnogs-uhf-702 satnogs-client[27801]: [INFO] Using format CF32.
Jul 18 19:04:05 satnogs-uhf-702 satnogs-client[27801]: Allocating 15 zero-copy buffers
Jul 18 19:11:24 satnogs-uhf-702 satnogs-client[27801]: usb_claim_interface error -6
Jul 18 19:11:24 satnogs-uhf-702 satnogs-client[27801]: Found Rafael Micro R820T tuner
Jul 18 19:11:24 satnogs-uhf-702 satnogs-client[27801]: [INFO] Opening Generic RTL2832U OEM :: 22...
Jul 18 19:11:24 satnogs-uhf-702 satnogs-client[27801]: Found Rafael Micro R820T tuner
Jul 18 19:11:25 satnogs-uhf-702 satnogs-client[27801]: [R82XX] PLL not locked!
Jul 18 19:11:25 satnogs-uhf-702 satnogs-client[27801]: [INFO] Using format CF32.
Jul 18 19:11:25 satnogs-uhf-702 satnogs-client[27801]: Allocating 15 zero-copy buffers
Jul 18 19:19:11 satnogs-uhf-702 satnogs-client[27801]: usb_claim_interface error -6
Jul 18 19:19:11 satnogs-uhf-702 satnogs-client[27801]: Found Rafael Micro R820T tuner
Jul 18 19:19:11 satnogs-uhf-702 satnogs-client[27801]: [INFO] Opening Generic RTL2832U OEM :: 22...
Jul 18 19:19:11 satnogs-uhf-702 satnogs-client[27801]: Found Rafael Micro R820T tuner
Jul 18 19:19:12 satnogs-uhf-702 satnogs-client[27801]: [R82XX] PLL not locked!
Jul 18 19:19:12 satnogs-uhf-702 satnogs-client[27801]: [INFO] Using format CF32.
Jul 18 19:19:12 satnogs-uhf-702 satnogs-client[27801]: Allocating 15 zero-copy buffers

What other log files should I check?
Will change the dongle just in case.

Thanks for your help.

Some other process (or a kernel module) seems to be using the device already. -6 means LIBUSB_ERROR_BUSY.

Oh, how in the world did I miss that! I know the -6 error only too well… Satnogs is running twice?

Ok, just changed the dongle as requested:

:~ $ rtl_test
Found 2 device(s):
  0:  Realtek, RTL2838UHIDIR, SN: 00000001
  1:  Realtek, RTL2838UHIDIR, SN: 222

Sure enough still getting the -6 error…

Jul 18 20:47:51 satnogs-uhf-702 systemd[1]: Stopped SatNOGS client.
Jul 18 20:47:51 satnogs-uhf-702 systemd[1]: Started SatNOGS client.
Jul 18 21:01:17 satnogs-uhf-702 satnogs-client[6994]: rot_init called
Jul 18 21:01:17 satnogs-uhf-702 satnogs-client[6994]: dummy: _init called
Jul 18 21:01:17 satnogs-uhf-702 satnogs-client[6994]: rot_register (1)
Jul 18 21:01:17 satnogs-uhf-702 satnogs-client[6994]: rot_register (2)
Jul 18 21:01:17 satnogs-uhf-702 satnogs-client[6994]: dummy_rot_init called
Jul 18 21:01:17 satnogs-uhf-702 satnogs-client[6994]: rot_open called
Jul 18 21:01:17 satnogs-uhf-702 satnogs-client[6994]: dummy_rot_open called
Jul 18 21:01:17 satnogs-uhf-702 satnogs-client[6994]: rot_get_position called
Jul 18 21:01:17 satnogs-uhf-702 satnogs-client[6994]: dummy_rot_get_position called
Jul 18 21:01:17 satnogs-uhf-702 satnogs-client[6994]: rot_set_position called
Jul 18 21:01:19 satnogs-uhf-702 satnogs-client[6994]: usb_claim_interface error -6
Jul 18 21:01:19 satnogs-uhf-702 satnogs-client[6994]: Found Rafael Micro R820T tuner
Jul 18 21:01:19 satnogs-uhf-702 satnogs-client[6994]: [INFO] Opening Generic RTL2832U OEM :: 222...
Jul 18 21:01:19 satnogs-uhf-702 satnogs-client[6994]: Found Rafael Micro R820T tuner
Jul 18 21:01:20 satnogs-uhf-702 satnogs-client[6994]: [R82XX] PLL not locked!
Jul 18 21:01:20 satnogs-uhf-702 satnogs-client[6994]: [INFO] Using format CF32.
Jul 18 21:01:20 satnogs-uhf-702 satnogs-client[6994]: Allocating 15 zero-copy buffers

This makes no sense.
Is the sudo satnogs-setup ignoring the serial number?

EDIT:
Ok, I am totally confused… you can see in the journalctl feed state that its using 222, but saying -6.
Its the only software using SDR222.
The other software BTW is high altitude balloon / radiosonde software and its working fine using 01.

Restarted the high altitude balloon service since changing the satnogs SDR serial number.
Now getting a new error I have not seen before.

Jul 18 21:45:03 satnogs-uhf-702 satnogs-client[11567]: [INFO] Opening Generic RTL2832U OEM :: 222...
Jul 18 21:45:03 satnogs-uhf-702 satnogs-client[11567]: usb_claim_interface error -6
Jul 18 21:45:03 satnogs-uhf-702 satnogs-client[11567]: Traceback (most recent call last):
Jul 18 21:45:03 satnogs-uhf-702 satnogs-client[11567]:   File "/usr/bin/satnogs_fsk.py", line 544, in <module>
Jul 18 21:45:03 satnogs-uhf-702 satnogs-client[11567]:     main()
Jul 18 21:45:03 satnogs-uhf-702 satnogs-client[11567]:   File "/usr/bin/satnogs_fsk.py", line 527, in main
Jul 18 21:45:03 satnogs-uhf-702 satnogs-client[11567]:     tb = top_block_cls(antenna=options.antenna, baudrate=options.baudrate, bb_freq=options.bb_freq, bw=options.bw, dc_removal=options.dc_removal, decoded_data_file_path=options.decoded_data_file_path, dev_args=options.dev_args, doppler_correction_per_sec=options.doppler_correction_per_sec, enable_iq_dump=options.enable_iq_dump, file_path=options.file_path, framing=options.framing, gain=options.gain, gain_mode=options.gain_mode, iq_file_path=options.iq_file_path, lo_offset=options.lo_offset, other_settings=options.other_settings, ppm=options.ppm, rigctl_port=options.rigctl_port, rx_freq=options.rx_freq, samp_rate_rx=options.samp_rate_rx, soapy_rx_device=options.soapy_rx_device, stream_args=options.stream_args, tune_args=options.tune_args, udp_IP=options.udp_IP, udp_dump_host=options.udp_dump_host, udp_dump_port=options.udp_dump_port, udp_port=options.udp_port, waterfall_file_path=options.waterfall_file_path)
Jul 18 21:45:03 satnogs-uhf-702 satnogs-client[11567]:   File "/usr/bin/satnogs_fsk.py", line 98, in __init__
Jul 18 21:45:03 satnogs-uhf-702 satnogs-client[11567]:     tune_args, settings, samp_rate_rx, "fc32")
Jul 18 21:45:03 satnogs-uhf-702 satnogs-client[11567]:   File "/usr/lib/python3/dist-packages/soapy/soapy_swig.py", line 166, in make
Jul 18 21:45:03 satnogs-uhf-702 satnogs-client[11567]:     return _soapy_swig.source_make(nchan, device, dev_args, stream_args, tune_args, other_settings, sampling_rate, type)
Jul 18 21:45:03 satnogs-uhf-702 satnogs-client[11567]: RuntimeError: Unable to open RTL-SDR device
Jul 18 21:45:07 satnogs-uhf-702 satnogs-client[11567]: satnogsclient.observer.observer - ERROR - No waterfall data file found

Does SatNOGS need the Pi to itself?
I can’t run any other SDR software on it at all?

It shouldn’t… Does it work when the radiosonde software is not running?

I’d remove the non-satnogs SDR for now to take it out of the equation. Total shot in the dark but wondering if SatNOGS is expecting a serial number to be 8 digits in length??? Maybe try serial=00000222 or omit the serial parameter from satnogs-setup after removing the non-SatNOGS SDR

Happened to me once when switching OSes. Can you check with lsmod which drivers are loaded? Have you had blacklisted kernel modules on Debian?

Thanks everyone.
I really did not want to use 2 computers when the one can do both tasks and more.

That said, it is important to understand little qwerks with each bit of software… The radiosonde guys reached out and let me know that if the Pi has more than one SDR attached, then neither SDR can have a serial number of 00000001 (as far as their software is concerned).
Once I found that out, I changed the serial number of the first SDR, restarted their software (all while SatNOGS was running) and everything has been run smoothly overnight with my usual results.

Its great to be back up and running and I hope the native Raspberry Pi install proves to be more reliable (as it is with my VHF station #908).

Cheers and thanks again for the help.

2 Likes

To clarify what the issue is here - radiosonde_auto_rx uses the rtl_fm and rtl_power utilities, which parse device numbers is kind of odd ways. If you give it a device number of ‘00000001’, it’ll interpret that as integer and use the first device in the list, even if it doesn’t have a serial number of ‘00000001’. This can cause issues when multiple devices are present. Best to change the serial numbers to something unique like ‘SONDE001’, ‘SATNOGS1’ and use those serials.