theori-io / nrsc5

NRSC-5 receiver for rtl-sdr
Other
805 stars 100 forks source link

Sporadic audio output issues ... #334

Open gstalnaker opened 1 year ago

gstalnaker commented 1 year ago

Linux HOLLIN 6.1.0-10-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.1.38-2 (2023-07-27) x86_64 GNU/Linux

MX Linux MX-23.1, KDE Plasma 5.27.5, Debian 12.2

nrsc5 revision 80ab64e, RTL-SDR v3 receiver, using the dipole attenna.

Short Story

Sometimes nrsc5 runs, appears to connect to the RTL-SDR dongle, and start playing the streams, only to have the audio stop playing.

Long Story

I Run nrsc5 at a terminal prompt:

*[master][~/bin/nrsc5-dui]$ /usr/local/bin/nrsc5 -q 104.1 1
Found Rafael Micro R820T tuner
Exact sample rate is: 1488375.071248 Hz
[R82XX] PLL not locked!
Allocating 8 zero-copy buffers

What I hear is a small blip, chirp, 5-10 seconds in, and then nothing. This happens both running nrsc5 from a terminal prompt and from within nrsc5-dui.

I run with logging enabled:

*[master][~/bin/nrsc5-dui]$ /usr/local/bin/nrsc5 -l 1 88.7 0
Found Rafael Micro R820T tuner
Exact sample rate is: 1488375.071248 Hz
[R82XX] PLL not locked!
Allocating 8 zero-copy buffers
21:22:47 Synchronized
21:22:47 Country: US, FCC facility ID: 63030
21:22:47 Station name: WERN-FM
21:22:47 Country: US, FCC facility ID: 63030
21:22:47 Station name: WERN-FM
21:22:47 Audio program 1: public, type: Public, sound experience 0
21:22:47 Audio program 2: public, type: Talk, sound experience 0
21:22:47 Country: US, FCC facility ID: 63030
21:22:47 Station name: WERN-FM
21:22:47 Slogan: MPS
21:22:47 Audio program 1: public, type: Public, sound experience 0
21:22:47 Audio program 2: public, type: Talk, sound experience 0
21:22:48 Country: US, FCC facility ID: 63030
21:22:48 Station name: WERN-FM
21:22:48 Slogan: MPS
21:22:48 Audio program 0: public, type: Public, sound experience 0
21:22:48 Audio program 1: public, type: Public, sound experience 0
21:22:48 Audio program 2: public, type: Talk, sound experience 0
21:22:48 Country: US, FCC facility ID: 63030
21:22:48 Station name: WERN-FM
21:22:48 Slogan: MPS
21:22:48 Station location: 99.214600, -11.968628, 128m
21:22:48 Audio program 0: public, type: Public, sound experience 0
21:22:48 Audio program 1: public, type: Public, sound experience 0
21:22:48 Audio program 2: public, type: Talk, sound experience 0
21:22:48 Country: US, FCC facility ID: 63030
21:22:48 Station name: WERN-FM
21:22:48 Slogan: MPS
21:22:48 Message:  
21:22:48 Station location: 99.214600, -11.968628, 128m
21:22:48 Audio program 0: public, type: Public, sound experience 0
21:22:48 Audio program 1: public, type: Public, sound experience 0
21:22:48 Audio program 2: public, type: Talk, sound experience 0
21:22:49 MER: 16.7 dB (lower), 16.7 dB (upper)
21:22:49 BER: 0.005834, avg: 0.005834, min: 0.005834, max: 0.005834
21:22:49 Title: 88.7WERN   WPR
21:22:49 Genre:  
21:22:49 Audio bit rate: 34.5 kbps

This is random across all of the six HD stations, and their subchannels, in Madison WI where I live.

It cannot be the RTL-SDR v3 dongle. Even when ncrs5(-dui) are having this "issue", I can run SDR++ and it works with audio output.

The audio configuration for my Linux box clearly shows that nrsc5 is connected to ALSA as along as I keep it running (without q or Ctrl-C). While running, changing channels (1, 2, 0) has no affect on the audio though I can clearly see the channel change (because Titles change if I have debug enabled). The debug output looks identical whether the audio is sounding or not sounding excepting channel information.

When it works, it's brilliant. Listened for three hours today to a subchannel I had no idea existed (Great American Songbook, Sinatra, etc.). When it doesn't work it's maddening.

I have ...

  1. Reset the dongle using usb command line tools; no change
  2. Restarted my computer; no change
  3. Detect no pattern for when I get continued audio output or only get the blip then nothing.
argilo commented 1 year ago

If you record the I/Q stream with -w <file> and then play it back with -r <file> in place of the frequency, does the audio output still fail during playback? (If so, please share the I/Q recording so I can have a look at it.)

If you redirect audio output to a WAV file with -o <file>, does the audio show up there, or does it also cut out?

gstalnaker commented 1 year ago

Additional Information

I was looking at the RTL-DSR Wiki and found hdfm. Figured I'd give it a try. Got it installed and ran it:

[~/src]$ /usr/local/bin/hdfm 104.1 1

It worked on my local channel 104.1 and I got audio output!

But I want channel 2, so I killed it and restarted it:

[~/src]$ /usr/local/bin/hdfm 104.1 2

And got the dreaded blip followed by no audio. It took 6 stop/starts before I got continuous audio on 104.1 2 (it's playing as I type this).

Why I'm adding data

The hdfm UI shows HDFM at the top left, the date and time top right. Below it puts album art on the left with channel data on the right:

As I waited for the D/A decoding to happen, I saw a zero 0 put in the Title: field, then in the Artist: field, then all the fields got populated with information.

That's when the blip sounded!

And no subsequent audio output.

It seems that there is a transition point in the signal processing where enough data is processed to populate the information display followed by audio output. That's when it horks.

I'll gather the requested audio files and report back.

gstalnaker commented 1 year ago

Interesting. I have an iq file with the blip:

https://www.dropbox.com/scl/fi/9nkp6fg2dnp36j4sfouvn/iq.out.zip?rlkey=63kbm2nr1rpww904ygnmvs5ul&dl=0

Cannot upload directly as it's 35Mb.

Interestingly I did the audio file output, piped into aplay, and it works. In fact, it seems to work everytime! I did a toggle this way:

[~/src]$ /usr/local/bin/hdfm 104.1 2  << AUDIO BLIP
[~/src]$ /usr/local/bin/nrsc5 -q -o - 104.1 2 | aplay << WORKED
Found Rafael Micro R820T tuner
Exact sample rate is: 1488375.071248 Hz
[R82XX] PLL not locked!
Allocating 8 zero-copy buffers
Playing WAVE 'stdin' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo
^CAborted by signal Interrupt...
aplay: pcm_write:2127: write error: Interrupted system call
[~/src]$ /usr/local/bin/hdfm 104.1 2    << AUDIO BLIP!
[~/src]$ /usr/local/bin/nrsc5 -q -o - 104.1 2 | aplay << WORKED
Found Rafael Micro R820T tuner
Exact sample rate is: 1488375.071248 Hz
[R82XX] PLL not locked!
Allocating 8 zero-copy buffers
Playing WAVE 'stdin' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo
1underrun!!! (at least 9905.998 ms long)
2underrun!!! (at least 3297.477 ms long)
1underrun!!! (at least 4093.729 ms long)
2underrun!!! (at least 12806.404 ms long)
1underrun!!! (at least 27350.209 ms long)

So, it seems that it's the onboard audio processing in nrsc5, as it fails with nrsc5 at a terminal, in hdfm (started from a terminal), and nrsc5-dui (both of these applications use nrsc5 as their backend processor) yet output of WAV piped into aplay works immediately after nrsc5 does not.

argilo commented 1 year ago

Strange, I haven't encountered that problem before. The main audio playback loop is here:

https://github.com/theori-io/nrsc5/blob/80ab64eeb2ba3378ed1ef7ef62508176329497ca/src/main.c#L800-L830

Perhaps you could add a printf after the ao_play line to see whether audio packets continue to be passed to libao (which interfaces with the audio hardware).

gstalnaker commented 1 year ago
821         printf("ao_play audio packet passed in next line\n"); 
822         ao_play(st->dev, b->data, sizeof(b->data));                                                                                            
823         printf("ao_play audio packet passed in previous line\n"); 

Produces no output visible on screen when the blip occurs.

*[master][~/bin/nrsc5-dui]$ /usr/local/bin/nrsc5 104.1 1                  
Found Rafael Micro R820T tuner                                                                                                                      
Exact sample rate is: 1488375.071248 Hz                                   
[R82XX] PLL not locked!                                                   
Allocating 8 zero-copy buffers                                            
00:38:10 Synchronized                                                     
00:38:10 Country: US, FCC facility ID: 41980                              
00:38:10 Station name: WZEE-FM                                            
00:38:10 Country: US, FCC facility ID: 41980                              
00:38:10 Station name: WZEE-FM                                            
00:38:10 Audio program 2: public, type: Religious Music, sound experience 0
00:38:10 Data service: public, type: Navigation, MIME type eb2    
00:38:11 Country: US, FCC facility ID: 41980                              
00:38:11 Station name: WZEE-FM                                                                                                                      
00:38:11 Audio program 2: public, type: Religious Music, sound experience 0
00:38:11 Data service: public, type: Navigation, MIME type eb2            
00:38:11 Data service: public, type: Navigation, MIME type 469            
00:38:11 Data service: public, type: Image Maps, MIME type 2d7            
00:38:11 Country: US, FCC facility ID: 41980                              
00:38:11 Station name: WZEE-FM                                                                                                                      
00:38:11 Station location: 37.755005, -122.452148, 2848m                  
00:38:11 Audio program 2: public, type: Religious Music, sound experience 0
00:38:11 Data service: public, type: Navigation, MIME type eb2                                                                                      
00:38:11 Data service: public, type: Navigation, MIME type 469            
00:38:11 Data service: public, type: Image Maps, MIME type 2d7       
00:38:11 Country: US, FCC facility ID: 41980                                                                                                        
00:38:11 Station name: WZEE-FM                                                                                                                      
00:38:11 Message:                                                                                                                                   
00:38:11 Station location: 37.755005, -122.452148, 2848m           
00:38:11 Audio program 2: public, type: Religious Music, sound experience 0
00:38:11 Data service: public, type: Navigation, MIME type eb2
00:38:11 Data service: public, type: Navigation, MIME type 469
00:38:11 Data service: public, type: Image Maps, MIME type 2d7
00:38:11 Country: US, FCC facility ID: 41980
00:38:11 Station name: WZEE-FM
00:38:11 Message:  
00:38:11 Station location: 37.755005, -122.452148, 2848m
00:38:11 Audio program 0: public, type: Top 40, sound experience 0
00:38:11 Audio program 2: public, type: Religious Music, sound experience 0
00:38:11 Data service: public, type: Navigation, MIME type eb2
00:38:11 Data service: public, type: Navigation, MIME type 469
00:38:11 Data service: public, type: Image Maps, MIME type 2d7
00:38:11 Data service: public, type: Image Maps, MIME type e96
00:38:12 MER: 9.2 dB (lower), 9.1 dB (upper)
00:38:12 Country: US, FCC facility ID: 41980
00:38:12 Station name: WZEE-FM
00:38:12 Message:  
00:38:12 Station location: 37.755005, -122.452148, 2848m
00:38:12 Audio program 0: public, type: Top 40, sound experience 0
00:38:12 Audio program 1: public, type: Classical, sound experience 0
00:38:12 Audio program 2: public, type: Religious Music, sound experience 0
00:38:12 Data service: public, type: Navigation, MIME type eb2
...
00:38:12 Data service: public, type: Image Maps, MIME type e96
00:38:12 BER: 0.005845, avg: 0.005845, min: 0.005845, max: 0.005845
00:38:12 Country: US, FCC facility ID: 41980
00:38:12 Station name: WZEE-FM
00:38:12 Message:  
00:38:12 Station location: 37.755005, -122.452148, 1920m
00:38:12 Audio program 0: public, type: Top 40, sound experience 0
00:38:12 Audio program 1: public, type: Classical, sound experience 0
00:38:12 Audio program 2: public, type: Religious Music, sound experience 0
00:38:12 Data service: public, type: Navigation, MIME type eb2
00:38:12 Data service: public, type: Navigation, MIME type 469
00:38:12 Data service: public, type: Image Maps, MIME type 2d7
00:38:12 Data service: public, type: Image Maps, MIME type e96
00:38:13 Country: US, FCC facility ID: 41980
00:38:13 Station name: WZEE-FM
00:38:13 Slogan: Z-104 All The Hits
00:38:13 Message:  
00:38:13 Station location: 37.755005, -122.452148, 1920m
00:38:13 Audio program 0: public, type: Top 40, sound experience 0
00:38:13 Audio program 1: public, type: Classical, sound experience 0
00:38:13 Audio program 2: public, type: Religious Music, sound experience 0
00:38:13 Data service: public, type: Navigation, MIME type eb2
00:38:13 Data service: public, type: Navigation, MIME type 469
00:38:13 Data service: public, type: Image Maps, MIME type 2d7
00:38:13 Data service: public, type: Image Maps, MIME type e96
00:38:13 MER: 12.6 dB (lower), 13.7 dB (upper)
00:38:13 BER: 0.000016, avg: 0.002931, min: 0.000016, max: 0.005845
00:38:13 Title: Canadian Sunset
00:38:13 Artist: Andy Williams
00:38:13 XHDR: 0 BE4B7536 10303
00:38:13 Title: Canadian Sunset
00:38:13 Artist: Andy Williams
00:38:13 XHDR: 0 BE4B7536 10303
00:38:13 Audio bit rate: 30.8 kbps
00:38:14 Country: US, FCC facility ID: 41980
00:38:14 Station name: WZEE-FM
00:38:14 Slogan: Z-104 All The Hits
00:38:14 Message:  
00:38:14 Station location: 37.755005, -122.452148, 3472m
00:38:14 Audio program 0: public, type: Top 40, sound experience 0
00:38:14 Audio program 1: public, type: Classical, sound experience 0
00:38:14 Audio program 2: public, type: Religious Music, sound experience 0
00:38:14 Data service: public, type: Navigation, MIME type eb2
00:38:14 Data service: public, type: Navigation, MIME type 469
00:38:14 Data service: public, type: Image Maps, MIME type 2d7
00:38:14 Data service: public, type: Image Maps, MIME type e96
00:38:15 MER: 9.8 dB (lower), 10.0 dB (upper)
00:38:15 BER: 0.007511, avg: 0.004458, min: 0.000016, max: 0.007511
00:38:15 Title: Canadian Sunset
00:38:15 Artist: Andy Williams
00:38:15 XHDR: 0 BE4B7536 10303
00:38:15 Audio bit rate: 30.6 kbps
^C

But does get shown when the audio output is successful:

*[master][~/bin/nrsc5-dui]$ /usr/local/bin/nrsc5 104.1 1
Found Rafael Micro R820T tuner
Exact sample rate is: 1488375.071248 Hz
[R82XX] PLL not locked!
Allocating 8 zero-copy buffers
00:40:11 Synchronized
00:40:11 Country: US, FCC facility ID: 41980
00:40:11 Station name: WZEE-FM
00:40:11 Country: US, FCC facility ID: 41980
00:40:11 Station name: WZEE-FM
00:40:11 Audio program 0: public, type: Top 40, sound experience 0
00:40:11 Data service: public, type: Image Maps, MIME type e96
00:40:11 Country: US, FCC facility ID: 41980
00:40:11 Station name: WZEE-FM
00:40:11 Audio program 0: public, type: Top 40, sound experience 0
00:40:11 Audio program 1: public, type: Classical, sound experience 0
00:40:11 Audio program 2: public, type: Religious Music, sound experience 0
00:40:11 Data service: public, type: Image Maps, MIME type e96
00:40:11 Country: US, FCC facility ID: 41980
00:40:11 Station name: WZEE-FM
00:40:11 Station location: 37.755005, -122.452148, 3520m
00:40:11 Audio program 0: public, type: Top 40, sound experience 0
00:40:11 Audio program 1: public, type: Classical, sound experience 0
00:40:11 Audio program 2: public, type: Religious Music, sound experience 0
00:40:11 Data service: public, type: Image Maps, MIME type e96
00:40:11 Country: US, FCC facility ID: 41980
00:40:11 Station name: WZEE-FM
00:40:11 Message:  
00:40:11 Station location: 37.755005, -122.452148, 3520m
00:40:11 Audio program 0: public, type: Top 40, sound experience 0
00:40:11 Audio program 1: public, type: Classical, sound experience 0
00:40:11 Audio program 2: public, type: Religious Music, sound experience 0
00:40:11 Data service: public, type: Image Maps, MIME type e96
00:40:11 Country: US, FCC facility ID: 41980
00:40:11 Station name: WZEE-FM
00:40:11 Message:  
00:40:11 Station location: 37.755005, -122.452148, 3520m
00:40:11 Audio program 0: public, type: Top 40, sound experience 0
00:40:11 Audio program 1: public, type: Classical, sound experience 0
00:40:11 Audio program 2: public, type: Religious Music, sound experience 0
00:40:11 Data service: public, type: Image Maps, MIME type e96
00:40:11 Data service: public, type: Navigation, MIME type eb2
00:40:11 Data service: public, type: Navigation, MIME type 469
00:40:12 MER: 11.7 dB (lower), 9.1 dB (upper)
00:40:12 Country: US, FCC facility ID: 41980
00:40:12 Station name: WZEE-FM
00:40:12 Message:  
00:40:12 Station location: 37.755005, -122.452148, 3520m
00:40:12 Audio program 0: public, type: Top 40, sound experience 0
00:40:12 Audio program 1: public, type: Classical, sound experience 0
00:40:12 Audio program 2: public, type: Religious Music, sound experience 0
00:40:12 Data service: public, type: Image Maps, MIME type e96
00:40:12 Data service: public, type: Navigation, MIME type eb2
00:40:12 Data service: public, type: Navigation, MIME type 469
00:40:12 Data service: public, type: Image Maps, MIME type 2d7
00:40:12 BER: 0.002909, avg: 0.002909, min: 0.002909, max: 0.002909
00:40:13 Country: US, FCC facility ID: 41980
00:40:13 Station name: WZEE-FM
00:40:13 Message:  
00:40:13 Station location: 37.755005, -122.452148, 2384m
00:40:13 Audio program 0: public, type: Top 40, sound experience 0
00:40:13 Audio program 1: public, type: Classical, sound experience 0
00:40:13 Audio program 2: public, type: Religious Music, sound experience 0
00:40:13 Data service: public, type: Image Maps, MIME type e96
00:40:13 Data service: public, type: Navigation, MIME type eb2
00:40:13 Data service: public, type: Navigation, MIME type 469
00:40:13 Data service: public, type: Image Maps, MIME type 2d7
00:40:13 Country: US, FCC facility ID: 41980
00:40:13 Station name: WZEE-FM
00:40:13 Slogan: Z-104 All The Hits
00:40:13 Message:  
00:40:13 Station location: 37.755005, -122.452148, 2384m
00:40:13 Audio program 0: public, type: Top 40, sound experience 0
00:40:13 Audio program 1: public, type: Classical, sound experience 0
00:40:13 Audio program 2: public, type: Religious Music, sound experience 0
00:40:13 Data service: public, type: Image Maps, MIME type e96
00:40:13 Data service: public, type: Navigation, MIME type eb2
00:40:13 Data service: public, type: Navigation, MIME type 469
00:40:13 Data service: public, type: Image Maps, MIME type 2d7
00:40:14 MER: 12.0 dB (lower), 12.6 dB (upper)
00:40:14 BER: 0.001442, avg: 0.002175, min: 0.001442, max: 0.002909
00:40:14 Title: Classical Highlights
00:40:14 Artist: 104.1 HD2
00:40:14 XHDR: 1 BE4B7536 -1
00:40:14 Title: Classical Highlights
00:40:14 Artist: 104.1 HD2
00:40:14 XHDR: 1 BE4B7536 -1
00:40:14 Audio bit rate: 30.9 kbps
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
00:40:14 Country: US, FCC facility ID: 41980
00:40:14 Station name: WZEE-FM
00:40:14 Slogan: Z-104 All The Hits
00:40:14 Message:  
00:40:14 Station location: 37.755005, -122.452148, 1136m
00:40:14 Audio program 0: public, type: Top 40, sound experience 0
00:40:14 Audio program 1: public, type: Classical, sound experience 0
00:40:14 Audio program 2: public, type: Religious Music, sound experience 0
00:40:14 Data service: public, type: Image Maps, MIME type e96
00:40:14 Data service: public, type: Navigation, MIME type eb2
00:40:14 Data service: public, type: Navigation, MIME type 469
00:40:14 Data service: public, type: Image Maps, MIME type 2d7
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
00:40:15 MER: 11.3 dB (lower), 12.4 dB (upper)
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
00:40:15 BER: 0.003831, avg: 0.002727, min: 0.001442, max: 0.003831
00:40:15 Title: Classical Highlights
00:40:15 Artist: 104.1 HD2
00:40:15 XHDR: 1 BE4B7536 -1
00:40:15 Audio bit rate: 30.4 kbps
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
00:40:16 Country: US, FCC facility ID: 41980
00:40:16 Station name: WZEE-FM
00:40:16 Slogan: Z-104 All The Hits
00:40:16 Message:  
00:40:16 Station location: 37.755005, -122.452148, 3344m
00:40:16 Audio program 0: public, type: Top 40, sound experience 0
00:40:16 Audio program 1: public, type: Classical, sound experience 0
00:40:16 Audio program 2: public, type: Religious Music, sound experience 0
00:40:16 Data service: public, type: Image Maps, MIME type e96
00:40:16 Data service: public, type: Navigation, MIME type eb2
00:40:16 Data service: public, type: Navigation, MIME type 469
00:40:16 Data service: public, type: Image Maps, MIME type 2d7
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
ao_play audio packet passed in previous line
ao_play audio packet passed in next line
^C
gstalnaker commented 1 year ago

Sorry I took so long to reply - I was looking for command line audio players I can use that provide controls in a gui, etc. rather than just route audio to ALSA like aplay, mpv, play, etc. Turns out audacious works. GUI pops up and I can change the volume in it. Can't do much else, but that's fine for now.

argilo commented 1 year ago

Interesting. Perhaps you could add some further logging, in particular around the pthread_cond_wait call, to see whether the audio thread is stuck waiting for a signal.

It's possible there could be a race condition somewhere.

gstalnaker commented 1 year ago

P.S. I LOVE that we're using printf() to do debugging. My god! LOL Takes me WAAAAAY back to when I learned to code C on a DEC VAX system at Stetson University in 1985.

gstalnaker commented 1 year ago
 805         while (!st->done && (st->head == NULL || st->audio_ready < AUDIO_THRESHOLD))                                                           
 806           {                                                                                                                                    
 807             printf("pthread_cond_wait in next line ...\n");                                                                                    
 808             printf("pthread_cond_wait(&st->cond, &st->mutex);\n");                                                                             
 809             pthread_cond_wait(&st->cond, &st->mutex);                                                                                          
 810           } 

Output:

*[master][~/bin/nrsc5-dui]$ /usr/local/bin/nrsc5 104.1 1
Found Rafael Micro R820T tuner
Exact sample rate is: 1488375.071248 Hz
[R82XX] PLL not locked!
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
Allocating 8 zero-copy buffers
01:01:09 Synchronized
01:01:09 Country: US, FCC facility ID: 41980
01:01:09 Station name: WZEE-FM
01:01:09 Country: US, FCC facility ID: 41980
01:01:09 Station name: WZEE-FM
01:01:09 Audio program 0: public, type: Top 40, sound experience 0
01:01:09 Data service: public, type: Image Maps, MIME type e96
01:01:10 Country: US, FCC facility ID: 41980
01:01:10 Station name: WZEE-FM
01:01:10 Audio program 0: public, type: Top 40, sound experience 0
01:01:10 Audio program 1: public, type: Classical, sound experience 0
01:01:10 Audio program 2: public, type: Religious Music, sound experience 0
01:01:10 Data service: public, type: Image Maps, MIME type e96
01:01:10 Country: US, FCC facility ID: 41980
01:01:10 Station name: WZEE-FM
01:01:10 Station location: 37.755005, -122.452148, 1440m
01:01:10 Audio program 0: public, type: Top 40, sound experience 0
01:01:10 Audio program 1: public, type: Classical, sound experience 0
01:01:10 Audio program 2: public, type: Religious Music, sound experience 0
01:01:10 Data service: public, type: Image Maps, MIME type e96
01:01:10 Country: US, FCC facility ID: 41980
01:01:10 Station name: WZEE-FM
01:01:10 Message:  
01:01:10 Station location: 37.755005, -122.452148, 1440m
01:01:10 Audio program 0: public, type: Top 40, sound experience 0
01:01:10 Audio program 1: public, type: Classical, sound experience 0
01:01:10 Audio program 2: public, type: Religious Music, sound experience 0
01:01:10 Data service: public, type: Image Maps, MIME type e96
01:01:10 Country: US, FCC facility ID: 41980
01:01:10 Station name: WZEE-FM
01:01:10 Message:  
01:01:10 Station location: 37.755005, -122.452148, 1440m
01:01:10 Audio program 0: public, type: Top 40, sound experience 0
01:01:10 Audio program 1: public, type: Classical, sound experience 0
01:01:10 Audio program 2: public, type: Religious Music, sound experience 0
01:01:10 Data service: public, type: Image Maps, MIME type e96
01:01:10 Data service: public, type: Navigation, MIME type eb2
01:01:10 Data service: public, type: Navigation, MIME type 469
01:01:11 MER: 12.9 dB (lower), 12.4 dB (upper)
01:01:11 Country: US, FCC facility ID: 41980
01:01:11 Station name: WZEE-FM
01:01:11 Message:  
01:01:11 Station location: 37.755005, -122.452148, 1440m
01:01:11 Audio program 0: public, type: Top 40, sound experience 0
01:01:11 Audio program 1: public, type: Classical, sound experience 0
01:01:11 Audio program 2: public, type: Religious Music, sound experience 0
01:01:11 Data service: public, type: Image Maps, MIME type e96
01:01:11 Data service: public, type: Navigation, MIME type eb2
01:01:11 Data service: public, type: Navigation, MIME type 469
01:01:11 Data service: public, type: Image Maps, MIME type 2d7
01:01:11 BER: 0.004118, avg: 0.004118, min: 0.004118, max: 0.004118
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
01:01:11 Country: US, FCC facility ID: 41980
01:01:11 Station name: WZEE-FM
01:01:11 Message:  
01:01:11 Station location: 37.755005, -122.452148, 3552m
01:01:11 Audio program 0: public, type: Top 40, sound experience 0
01:01:11 Audio program 1: public, type: Classical, sound experience 0
01:01:11 Audio program 2: public, type: Religious Music, sound experience 0
01:01:11 Data service: public, type: Image Maps, MIME type e96
01:01:11 Data service: public, type: Navigation, MIME type eb2
01:01:11 Data service: public, type: Navigation, MIME type 469
01:01:11 Data service: public, type: Image Maps, MIME type 2d7
01:01:12 Country: US, FCC facility ID: 41980
01:01:12 Station name: WZEE-FM
01:01:12 Slogan: Z-104 All The Hits
01:01:12 Message:  
01:01:12 Station location: 37.755005, -122.452148, 3552m
01:01:12 Audio program 0: public, type: Top 40, sound experience 0
01:01:12 Audio program 1: public, type: Classical, sound experience 0
01:01:12 Audio program 2: public, type: Religious Music, sound experience 0
01:01:12 Data service: public, type: Image Maps, MIME type e96
01:01:12 Data service: public, type: Navigation, MIME type eb2
01:01:12 Data service: public, type: Navigation, MIME type 469
01:01:12 Data service: public, type: Image Maps, MIME type 2d7
01:01:12 MER: 13.1 dB (lower), 13.6 dB (upper)
01:01:12 BER: 0.003888, avg: 0.004003, min: 0.003888, max: 0.004118
01:01:12 Title: Don't Break The Heart That Loves You
01:01:12 Artist: Connie Francis
01:01:12 XHDR: 0 BE4B7536 10600
01:01:12 Audio bit rate: 30.5 kbps
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
pthread_cond_wait in next line ...
pthread_cond_wait(&st->cond, &st->mutex);
ao_play audio packet passed in next line...
ao_play(st->dev, b->data, sizeof(b->data));
01:01:13 Country: US, FCC facility ID: 41980
01:01:13 Station name: WZEE-FM
01:01:13 Slogan: Z-104 All The Hits
01:01:13 Message:  
01:01:13 Station location: 37.755005, -122.452148, 2960m
01:01:13 Audio program 0: public, type: Top 40, sound experience 0
01:01:13 Audio program 1: public, type: Classical, sound experience 0
01:01:13 Audio program 2: public, type: Religious Music, sound experience 0
01:01:13 Data service: public, type: Image Maps, MIME type e96
01:01:13 Data service: public, type: Navigation, MIME type eb2
01:01:13 Data service: public, type: Navigation, MIME type 469
01:01:13 Data service: public, type: Image Maps, MIME type 2d7
01:01:14 MER: 8.6 dB (lower), 9.4 dB (upper)
01:01:14 BER: 0.003653, avg: 0.003887, min: 0.003653, max: 0.004118
01:01:14 Title: Don't Break The Heart That Loves You
01:01:14 Artist: Connie Francis
01:01:14 XHDR: 0 BE4B7536 10600
01:01:14 Audio bit rate: 31.0 kbps
01:01:14 Country: US, FCC facility ID: 41980
01:01:14 Station name: WZEE-FM
01:01:14 Slogan: Z-104 All The Hits
01:01:14 Message:  
01:01:14 Station location: 37.755005, -122.452148, 3504m
01:01:14 Audio program 0: public, type: Top 40, sound experience 0
01:01:14 Audio program 1: public, type: Classical, sound experience 0
01:01:14 Audio program 2: public, type: Religious Music, sound experience 0
01:01:14 Data service: public, type: Image Maps, MIME type e96
01:01:14 Data service: public, type: Navigation, MIME type eb2
01:01:14 Data service: public, type: Navigation, MIME type 469
01:01:14 Data service: public, type: Image Maps, MIME type 2d7
gstalnaker commented 1 year ago

NM about adding time stamp. I see I can use the log_info() function for that.

argilo commented 1 year ago

From your log, it seems like maybe the audio thread is getting stuck trying to lock the mutex. Could you add unique log messages before and after each of the two pthread_mutex_lock calls?

gstalnaker commented 1 year ago

In the while() loop:

        log_info("DEBUG: Before first pthread_mutex_lock(&st->mutex);\n");
        pthread_mutex_lock(&st->mutex);
        log_info("DEBUG: After first pthread_mutex_lock(&st->mutex);\n");
...
        log_info("DEBUG: Before second pthread_mutex_lock(&st->mutex);\n");
        pthread_mutex_lock(&st->mutex);
        log_info("DEBUG: After second pthread_mutex_lock(&st->mutex);\n");

Also enabled the other two DEBUG lines you've asked for.

Log is attached. the first pthread_mutex_lock is logged, but not the second one. There is one ao_play, with, as before, interspersed pthread_cond_waits.

20231120.1503_nrsc5_NAK.log

I should mention that this is an MXLinux box and it does not use SystemD. PulseAudio is running.

argilo commented 1 year ago

Do you still have a debug line after the ao_play? It could be that ao_play never returns.

argilo commented 1 year ago

Also, could you post the contents of /etc/libao.conf?

argilo commented 1 year ago

I booted up MX Linux in a VM, and I see that /etc/libao.conf has default_driver=alsa. Could you try changing that to default_driver=pulse to see whether it helps?

gstalnaker commented 1 year ago

Sorry I didn't respond yesterday. I did not have the DEBUG line after ao_play. I have put it there for a new run. With the change to the /etc/libao.conf file, the blip does not occur in sequenced testing. Yesterday I had to run nrsc5 maybe six times before I got sound past the blip. Today with that change five successive runs and no blip. I appreciate you going to the trouble to spin up a VM for MX Linux. I'd have never thought to look at any file in /etc/. I'll use it today and report back.

argilo commented 1 year ago

Thanks for the update. It seems like libao's ALSA driver is a likely culprit. Here's a similar case that another project ran into: https://github.com/PromyLOPh/pianobar/issues/623

I haven't encountered the issue because Ubuntu switched the default driver to Pulse, but the upstream Debian package still defaults to ALSA.

Perhaps this is another good reason to switch from libao to PortAudio, as was previously contemplated in https://github.com/theori-io/nrsc5/issues/265#issuecomment-950387916. The only downside is that PortAudio doesn't have any built-in support for writing WAV files, so we'd either need to roll or own or use something like libsndfile (which would have the benefit of supporting other output formats).

gstalnaker commented 1 year ago

Perhaps a comment in the README.md file that specifically mentions checking the conf file to confirm it's set to pulse. Or a modification to the "make install" to put in place, or modify, the conf file. That is a fairly trivial change for users to make (and certainly easier than writing code -- well for me to write that code).

gstalnaker commented 1 year ago

Now to get nrsc5-dui's GUI to stop failing (interestingly, the nrsc5 process it spawns continues to work, and play music, but the GUI simply goes away).

markjfine commented 1 year ago

Now to get nrsc5-dui's GUI to stop failing (interestingly, the nrsc5 process it spawns continues to work, and play music, but the GUI simply goes away).

That's not good... Raise an issue over there with whatever pertinent info you can provide and I'll take a look into it.

gstalnaker commented 1 year ago

Of course, right now it's working just fine, though I did start it differently - at a prompt specifying frequency and channel.

jasprs06 commented 6 months ago

Windows 10 version The sample will play fine. When I try a radio station it might play audio for a few seconds and quit then if I let it run it might play a few seconds again and so on. I see in the file I am sending you it keeps losing synchronization and the very next line says Synchronized. It then has 4 lines of data then loses synchronization again and repeats over and over. NRSC5 error.txt