search

jks-prv / Beagle_SDR_GPS

KiwiSDR: BeagleBone web-accessible shortwave receiver and software-defined GPS
http://kiwisdr.com
481 stars 161 forks source link

kiwid stalls on sdr.hu registration #41

Closed rikvanriel closed 7 years ago

rikvanriel commented 8 years ago

I have noticed occasional stalls of the waterfall and audio. I finally managed to grab a backtrace, and it turns out to be the sdr.hu registration that can take several seconds, stalling the kiwid process while waiting for the sdr.hu http request to complete (or the connection to be made?).

gdb --batch -p pidof kiwid -ex "bt" -ex "quit"

__libc_do_syscall () at ../ports/sysdeps/unix/sysv/linux/arm/libc-do-syscall.S:43 43 ../ports/sysdeps/unix/sysv/linux/arm/libc-do-syscall.S: No such file or directory.

0 __libc_do_syscall () at ../ports/sysdeps/unix/sysv/linux/arm/libc-do-syscall.S:43

1 0xb6c1650a in _IO_new_proc_close (fp=0x495d7d8) at iopopen.c:345

2 0xb6c1d1c4 in _IO_new_file_close_it (fp=fp@entry=0x495d7d8) at fileops.c:171

3 0xb6c1514c in _IO_new_fclose (fp=0x495d7d8) at iofclose.c:59

4 0x0002ea98 in non_blocking_cmd (cmd=, reply=0x49ea468 "<!doctype html>\n\n\n\tSDR.hu\n\t<meta charset=\"utf-8\" />\n\t<meta http-equiv=\"X-UA-Compatible\" content=\"IE=edge\">\n\t<!--<meta name=\"viewport\" content=\"width=1000, initial-scale=1\" >"..., reply_size=16384, status=0x0) at support/misc.c:318

5 0x00023b38 in reg_SDR_hu (param=0x0) at web/services.c:137

6 0x00048dda in trampoline () at support/coroutines.cpp:451

7 0x00048dc4 in TaskRemove (id=) at support/coroutines.cpp:653

rikvanriel commented 8 years ago

During these stalls, kiwid CPU usage drops to zero. It looks like maybe non_blocking_cmd is not as non blocking as hoped...

jks-prv commented 8 years ago

How long are the stalls you are observing?

rikvanriel commented 8 years ago

They last several seconds, long enough for the waterfall and sound buffers to run out. I think the longest I have seen is on the order of 10-15 seconds.

rikvanriel commented 8 years ago

The stalls seem to correspond with failed sdr.hu registrations in /var/log/messages

Oct 25 04:42:34 kiwisdr kiwid: 2:12:15 0... sdr.hu registration: FAILED n=0 sp=(nil) Oct 25 04:42:34 kiwisdr rsyslogd-2007: action 'action 17' suspended, next retry is Tue Oct 25 04:44:04 2016 [try http://www.rsyslog.com/e/2007 ] Oct 25 04:44:15 kiwisdr rsyslogd-2007: action 'action 17' suspended, next retry is Tue Oct 25 04:45:45 2016 [try http://www.rsyslog.com/e/2007 ] Oct 25 04:45:01 kiwisdr kiwid: 2:14:42 0... sdr.hu registration: FAILED n=1199 sp=(nil)

jks-prv commented 8 years ago

Hmm. For the case where there is something in the reply buffer (n=1199 instead of zero), but the "UPDATE:" token isn't found as expected, it would be interesting to see what was in the buffer by using gdb. I don't log anything in this case (except saying "FAILED") because the buffer is likely to just contain a whole bunch of HTML.

rikvanriel commented 8 years ago

Here is what I got back:

Oct 25 05:33:12 kiwisdr kiwid: 0:00:28 .... sdr.hu registration: FAILED n=1199 sp=(nil) reply=<!doctype html>#012#012#012#011SDR.hu#012#011#012#011#012#011<!-- #012#011#012#011#012#011#012#011#012#011#012#011#012#011#012#011#012#011#012#011 Githubissues.

  • Githubissues is a development platform for aggregating issues.