dbus exception when running channel scan

Parameter 0 is the channel's frequency, a uint. It's weird that it tries to convert the value to (null).

Hmm, I ran gnome-dvb-daemon in debug mode and I got failure (not handled by UI). It works if I use dvbscan with the same dvb-t file for Paris.

log :

** (gnome-dvb-daemon:13186): DEBUG: Main.vala:128: Has dvbsrc >= 0.10.13: true
** (gnome-dvb-daemon:13186): DEBUG: Main.vala:128: Has dvbbasebin >= 0.10.13: true
** (gnome-dvb-daemon:13186): DEBUG: Main.vala:128: Has mpegtsparse >= 0.10.13: true
** (gnome-dvb-daemon:13186): DEBUG: Main.vala:128: Has rtpmp2tpay >= 0.10.14: true
** Message: Main.vala:55: Creating new Manager D-Bus service
** Message: Main.vala:193: Restoring device groups
** Message: Main.vala:76: Creating new RecordingsStore D-Bus service
** Message: Server.vala:26: Starting RTSP server
** Message: listening on port 8554
** Message: Services.vala:293: Creating new Rygel MediaServer D-Bus service
** (gnome-dvb-daemon:13186): DEBUG: Manager.vala:174: Created new Scanner D-Bus service for adapter 0, frontend 0 (org.gnome.DVB.Scanner.Terrestrial)
** (gnome-dvb-daemon:13186): DEBUG: TerrestrialScanner.vala:95: Reading scanning data from /usr/share/dvb/dvb-t/fr-Paris
** (gnome-dvb-daemon:13186): DEBUG: Scanner.vala:308: Queueing new frequency 474166000
** (gnome-dvb-daemon:13186): DEBUG: Scanner.vala:308: Queueing new frequency 498166000
** (gnome-dvb-daemon:13186): DEBUG: Scanner.vala:308: Queueing new frequency 522166000
** (gnome-dvb-daemon:13186): DEBUG: Scanner.vala:308: Queueing new frequency 538166000
** (gnome-dvb-daemon:13186): DEBUG: Scanner.vala:308: Queueing new frequency 562166000
** (gnome-dvb-daemon:13186): DEBUG: Scanner.vala:308: Queueing new frequency 586166000
** (gnome-dvb-daemon:13186): DEBUG: Scanner.vala:308: Queueing new frequency 714166000
** (gnome-dvb-daemon:13186): DEBUG: Scanner.vala:308: Queueing new frequency 738166000
** (gnome-dvb-daemon:13186): DEBUG: Scanner.vala:308: Queueing new frequency 754166000
** (gnome-dvb-daemon:13186): DEBUG: Scanner.vala:308: Queueing new frequency 762166000
** (gnome-dvb-daemon:13186): DEBUG: Scanner.vala:308: Queueing new frequency 786166000
** (gnome-dvb-daemon:13186): DEBUG: Scanner.vala:308: Queueing new frequency 810166000
** (gnome-dvb-daemon:13186): DEBUG: Scanner.vala:321: Received all tables: false (pat: false, sdt: false, nit: false, pmt: false)
** (gnome-dvb-daemon:13186): DEBUG: Scanner.vala:360: Starting scanning frequency 474166000 (11 left)
** (gnome-dvb-daemon:13186): DEBUG: TerrestrialScanner.vala:153: Setting up pipeline for DVB-T scan
** (gnome-dvb-daemon:13186): DEBUG: Scanner.vala:321: Received all tables: false (pat: false, sdt: false, nit: false, pmt: false)
** (gnome-dvb-daemon:13186): DEBUG: Scanner.vala:360: Starting scanning frequency 498166000 (10 left)
** (gnome-dvb-daemon:13186): DEBUG: TerrestrialScanner.vala:153: Setting up pipeline for DVB-T scan
** (gnome-dvb-daemon:13186): DEBUG: Scanner.vala:433: Got lock

** (gnome-dvb-daemon:13186): WARNING **: Scanner.vala:443: Read failure

** (gnome-dvb-daemon:13186): WARNING **: Scanner.vala:443: Read failure

** (gnome-dvb-daemon:13186): WARNING **: Scanner.vala:443: Read failure

** (gnome-dvb-daemon:13186): WARNING **: Scanner.vala:443: Read failure

** (gnome-dvb-daemon:13186): WARNING **: S...

The last critical is caused if an error is posted on the bus and it tries to dispose the pipeline while it's still running. However, it's not clear what caused the error in the first place. Could you run the daemon in gdb with G_DEBUG=fatal-criticals and post the stacktrace, please.

backstrace :

Starting program: /usr/bin/gnome-dvb-daemon
[Thread debugging using libthread_db enabled]
** Message: Main.vala:55: Creating new Manager D-Bus service
** Message: Main.vala:193: Restoring device groups
** Message: Main.vala:76: Creating new RecordingsStore D-Bus service
** Message: Server.vala:26: Starting RTSP server
** Message: listening on port 8554
** Message: Services.vala:293: Creating new Rygel MediaServer D-Bus service
[New Thread 0xb76afb70 (LWP 22935)]
[New Thread 0xb6c82b70 (LWP 22957)]

** (gnome-dvb-daemon:22912): WARNING **: Scanner.vala:443: Read failure

** (gnome-dvb-daemon:22912): WARNING **: Scanner.vala:443: Read failure

** (gnome-dvb-daemon:22912): WARNING **: Scanner.vala:443: Read failure

** (gnome-dvb-daemon:22912): WARNING **: Scanner.vala:443: Read failure

** (gnome-dvb-daemon:22912): WARNING **: Scanner.vala:443: Read failure

** (gnome-dvb-daemon:22912): WARNING **: Scanner.vala:443: Read failure

** (gnome-dvb-daemon:22912): WARNING **: Scanner.vala:443: Read failure

** (gnome-dvb-daemon:22912): WARNING **: Scanner.vala:443: Read failure

** (gnome-dvb-daemon:22912): WARNING **: Scanner.vala:443: Read failure

** (gnome-dvb-daemon:22912): WARNING **: Scanner.vala:443: Read failure

** (gnome-dvb-daemon:22912): WARNING **: Scanner.vala:443: Read failure

** CRITICAL **: Scanner.vala:698: Erreur interne de flux de données. gstbasesrc.c(2507): gst_base_src_loop (): /GstPipeline:pipeline0/GstDvbSrc:dvbsrc:
streaming task paused, reason error (-5)
aborting...

Program received signal SIGTRAP, Trace/breakpoint trap.
IA__g_logv (log_domain=<value optimized out>, log_level=G_LOG_LEVEL_CRITICAL,
    format=0x80fc1c5 "Scanner.vala:698: %s %s",
    args1=0xbfffed8c "À*&\b¨æ&\bÿÿÿÿ\001") at gmessages.c:555
555 g_private_set (g_log_depth, GUINT_TO_POINTER (depth));
(gdb) thread apply all bt

Thread 3 (Thread 0xb6c82b70 (LWP 22957)):
#0 0xb7ff9713 in strcmp (p1=0xb7ba2a7f "g_static_rec_mutex_unlock_full",
    p2=0xb7ccc7a4 "g_static_rec_mutex_unlock_full") at strcmp.c:41
#1 0xb7febdbc in check_match (sym=0xb7b9d63c) at dl-lookup.c:150
#2 0xb7fec484 in do_lookup_x (new_hash=<value optimized out>,
    old_hash=0xb6c821f4, ref=0xb7cbfa08, result=0xb6c821e8, scope=0xb7fffa64,
    i=11, flags=5, skip=0x0, undef_map=0xb7e5b850) at dl-lookup.c:250
#3 0xb7fec6e8 in _dl_lookup_symbol_x (undef_name=<value optimized out>,
    undef_map=<value optimized out>, ref=0xb6c82230, symbol_scope=0xb7e5ba08,
    version=0x0, type_class=1, flags=5, skip_map=0x0) at dl-lookup.c:721
#4 0xb7ff0be5 in _dl_fixup (l=<value optimized out>,
    reloc_arg=<value optimized out>) at dl-runtime.c:118
#5 0xb7ff68d0 in _dl_runtime_resolve () at ../sysdeps/i386/dl-trampoline.S:37
#6 0xb7d3da08 in gst_task_func (task=0xb6d03810) at gsttask.c:221
#7 0xb7d3efe8 in default_func (tdata=0xb6d00db8, pool=0x811ac10)
    at gsttaskpool.c:70
#8 0xb7bfbfbf in g_thread_pool_thread_proxy (data=0x811b010)
    at gthreadpool.c:315
#9 0xb7bf9f64 in g_thread_create_proxy (data=0xb6d04088) at gthread.c:1893
#10 0xb7b82ae5 in start_thread () from /lib/i686/libpthread.so.0
#11 0xb7b0300e in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:13...

Could please check if the attached patch helps.

it is a little better (scan finishes) but it doesn't find any station :(

You have attached the wrong file ;)

oops, right file attached

The debug log shows "Channel added", therefore you should see at least 5 channels. Have you checked if gnome-dvb-setup shows any errors?

That fact that some channels (but not all) are missing might be related to a bug in GStreamer which I already have a patch for and it's waiting to be committed.

The warning at the end is weird, could you get a trace with G_DEBUG=fatal-warnings for that one, please.

do you have a bug number for gstreamer issue ? I could test the patch.

gnome-dvb-setup is showing the exception from comment #0 (on self.emit ("channel-added")) and also exception on "self.emit("frequency-scanned")).

backtrace for the last warning :

GLib-GObject-WARNING **: value "-10" of type `gint' is invalid or out of range for property `frequency' of type `gint'
aborting...

Program received signal SIGABRT, Aborted.
[Switching to Thread 0xb76b6b70 (LWP 13622)]
0xffffe424 in __kernel_vsyscall ()
(gdb) thread apply all bt

Thread 2 (Thread 0xb76b6b70 (LWP 13622)):
#0 0xffffe424 in __kernel_vsyscall ()
#1 0xb7a5ba81 in raise (sig=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#2 0xb7a5d3d2 in abort () at abort.c:92
#3 0xb7be067c in IA__g_logv (log_domain=<value optimized out>,
    log_level=G_LOG_LEVEL_WARNING,
    format=0xb7cb0f00 "value \"%s\" of type `%s' is invalid or out of range for property `%s' of type `%s'",
    args1=0xb76b5ffc "\030\033ж\rnË·Pâ\031\b\rnË·à\036Ê·\rnË·\030\033ж¸`k·0J0¶h\003Ì·d\003Ì·ø¤&\b\004") at gmessages.c:549
#4 0xb7be06a7 in IA__g_log (log_domain=0xb7caf984 "GLib-GObject",
    log_level=G_LOG_LEVEL_WARNING,
    format=0xb7cb0f00 "value \"%s\" of type `%s' is invalid or out of range for property `%s' of type `%s'") at gmessages.c:569
#5 0xb7c8c01d in object_set_property (nqueue=<value optimized out>,
    value=<value optimized out>, pspec=<value optimized out>,
    object=<value optimized out>) at gobject.c:964
#6 IA__g_object_set_valist (nqueue=<value optimized out>,
    value=<value optimized out>, pspec=<value optimized out>,
    object=<value optimized out>) at gobject.c:1488
#7 0xb7c8c1c8 in IA__g_object_set (_object=0x826a4f0,
    first_property_name=0x80e7a91 "frequency") at gobject.c:1594
#8 0x080d5a39 in dvb_scanner_set_uint_property (src=0x826a4f0,
    params=0xb631f660, key=0x80e7a91 "frequency") at src/Scanner.c:923
#9 0x0806989f in dvb_terrestrial_scanner_real_prepare (base=0x8270018)
    at src/Terrestrial/TerrestrialScanner.c:2516
#10 0x080d6e04 in dvb_scanner_start_scan (self=0x8270018) at src/Scanner.c:791
#11 0xb7bd3d00 in g_idle_dispatch (source=0xb6d01b38, callback=0,
    user_data=0x8270018) at gmain.c:4065
#12 0xb7bd5c8e in g_main_dispatch (context=<value optimized out>)
    at gmain.c:1960
#13 IA__g_main_context_dispatch (context=<value optimized out>) at gmain.c:2513
#14 0xb7bd99c8 in g_main_context_iterate (context=0x81a0200,
    block=<value optimized out>, dispatch=1, self=0x819f1d8) at gmain.c:2591
#15 0xb7bd9ed7 in IA__g_main_loop_run (loop=0x8122b08) at gmain.c:2799
#16 0x080d79b9 in dvb_scanner_worker (self=<value optimized out>)
    at src/Scanner.c:621
#17 _dvb_scanner_worker_gthread_func (self=<value optimized out>)
    at src/Scanner.c:297
#18 0xb7c00c14 in g_thread_create_proxy (data=0x819f1d8) at gthread.c:1893
#19 0xb7b89ae5 in start_thread () from /lib/i686/libpthread.so.0
#20 0xb7b0a00e in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:130

Thread 1 (Thread 0xb77fe6c0 (LWP 13607)):
#0 0xffffe424 in __kernel_vsyscall ()
---Type <return> to continue, or q <return> to quit---
#1 0xb7afeb16 in __poll (fds=0xb7b7fff4, nfds=4, timeout=1951)
...

My patch is available at https://bugzilla.gnome.org/show_bug.cgi?id=614479

There seems to be some kind of problem with signed and unsigend ints. The property setter of dvbsrc expects an int whereas it should except uint, which is used internally anyway (see https://bugzilla.gnome.org/show_bug.cgi?id=614475). Something similar seems to happen when the signals are emitted.

That means we have to dig deeper: What architecture are you running and which version of Vala do you use?

It would be great if you could upload a short recording (10-20s are enough) somewhere so I can check if something went wrong in GStreamer. You can create a proper channels.conf with dvb-app's scan and the file /usr/share/dvb/dvb-t/fr-Paris. If you start gnome-dvb-control and go to preferences you can manually add a device specify the channels.conf from scan.

architecture : x86
vala used : 0.7.10 (vala 0.8.0 landed on cooker since but I didn't test yet)

I'll try to do some test with your patches on gstreamer later.

It appears fr-Paris might not be right because dvb-app scan didn't find all available channels, unlike a full scan.

I did a recording for 1min, available at http://dl.free.fr/vyrz7yo4B with the "partial" scan file.

I had a closer look at the file you provided. GStreamer retrieves the correct information, the file claims a frequency of 0xffff which then causes the uint/int issue. Obviously, such frequency doesn't make sense. Dies dvb-apps scan find no channels at all or are just some missing, in the latter case I should take a closer look how they deal with this situation.

dvb-apps scan finds "some" channels, but not all of them (I can attach both channels.conf file, if you are interested)

The GStreamer bugs are now fixed in their git version.

Regarding the wrong/missing channels issue bug #548738 already covers that, please discuss this issue there.

ok, I can confirm the dbus exceptions are gone with the gstreamer fixes, but I don't have any channel found during a scan and I now have "warning: error tuning channel: invalid argument".

I'll switch to bug #548738 for the channel not found (btw, you should use different names for patches, calling all of them scanner.patch is not a good idea ;)

oops, my bad, I just saw one single dbus exception at the end of the scan (no channel was found) :

  self.emit("frequency-scanned", freq, freq_left)
TypeError: could not convert type dbus.UInt32 to (null) required for parameter 0

Where does the message "warning: error tuning channel: invalid argument" appear, could you post debug log, please?

I suppose the dbus exception is caused by the value being to big for uint32. This should disappear with the patch from bug #548738, because tuning data contained in the transport stream is no longer used (sorry about the confusion with the patch names).

and from kernel log :

DVB: adapter 0 frontend 0 frequency 4294967286 out of range (45000000..860000000)

is output when invalid argument is returned.