Ticket #362 (closed bug: fixed)

Opened 8 years ago

Last modified 8 years ago

ffado-dbus-server crashes when launching ffado-mixer

Reported by: andreeecz Assigned to: arnonym
Priority: major Milestone: FFADO 2.x
Component: ffado-mixer Version: FFADO SVN (trunk)
Keywords: Cc:
The device the bug applies to: SaffirePro40

Description

Jack is running smooth, all ports present, pulse is bridged. Upon ffado-mixer launch, it says that it cant connect to ffado-dbus-server. If ffado-dbus-server is launched solo, it crashes right when ffado-mixer is launched.

System Specs:

Arch Linux,
Intel C2D@2.4
3GB RAM
Express Card TI FW
Saffire Pro40

ffado-diag

[andre@andre ~]$ ffado-diag 


FFADO diagnostic utility 2.999.0-2205M
============================
(C) 2008 Pieter Palmers
    2009-2010 Arnold Krille


=== CHECK ===
 Base system...
  kernel version............ 3.5.3-1-ARCH
    Preempt (low latency)... True
    RT patched.............. False
  old 1394 stack present.... False
  old 1394 stack loaded..... False
  old 1394 stack active..... False
  new 1394 stack present.... False
  new 1394 stack loaded..... True
  new 1394 stack active..... True
  /dev/raw1394 node present. False
  /dev/fw* permissions:
crw-------  1 root root  250, 0 Sep 10 18:59 /dev/fw0
crw-------  1 root root  250, 1 Sep 10 18:59 /dev/fw1
crw-rw----+ 1 root audio 250, 2 Sep 10 18:59 /dev/fw2
  User IDs:
uid=1000(andre) gid=100(users) groups=100(users),7(lp),10(wheel),90(network),91(video),92(audio),93(optical),95(storage),98(power),108(vboxusers),1001(realtime)
 Prerequisites (dynamic at run-time)...
   gcc ............... gcc (GCC) 4.7.1 20120721 (prerelease)
   g++ ............... g++ (GCC) 4.7.1 20120721 (prerelease)
   PyQt4 (by pyuic4) . Python User Interface Compiler 4.9.4 for Qt version 4.8.2
   jackd ............. no message buffer overruns
     path ............ /usr/bin/jackd
     flags ...........  -ljack  
   libraw1394 ........ 2.0.7
     flags ...........  -lraw1394  
   libavc1394 ........ 0.5.4
     flags ...........  -lavc1394 -lrom1394 -lraw1394  
   libiec61883 ....... 1.2.0
     flags ...........  -liec61883 -lraw1394  
   libxml++-2.6 ...... 2.34.2
     flags ........... -I/usr/include/libxml++-2.6 -I/usr/lib/libxml++-2.6/include -I/usr/include/libxml2 -I/usr/include/glibmm-2.4 -I/usr/lib/glibmm-2.4/include -I/usr/include/sigc++-2.0 -I/usr/lib/sigc++-2.0/include -I/usr/include/glib-2.0 -I/usr/lib/glib-2.0/include  -lxml++-2.6 -lxml2 -lglibmm-2.4 -lgobject-2.0 -lsigc-2.0 -lglib-2.0  
   dbus-1 ............ 1.6.4
     flags ........... -I/usr/include/dbus-1.0 -I/usr/lib/dbus-1.0/include  -ldbus-1  
 Prerequisites (static at compile-time)...
   gcc ............... gcc (GCC) 4.7.1 20120721 (prerelease)
   g++ ............... g++ (GCC) 4.7.1 20120721 (prerelease)
   PyQt4 (by pyuic4) . Python User Interface Compiler 4.9.4 for Qt version 4.8.2
   jackd ............. no message buffer overruns
     path ............ /usr/bin/jackd
     flags ...........  -ljack  
   libraw1394 ........ 2.0.7
     flags ...........  -lraw1394  
   libavc1394 ........ 0.5.4
     flags ...........  -lavc1394 -lrom1394 -lraw1394  
   libiec61883 ....... 1.2.0
     flags ...........  -liec61883 -lraw1394  
   libxml++-2.6 ...... 2.34.2
     flags ........... -I/usr/include/libxml++-2.6 -I/usr/lib/libxml++-2.6/include -I/usr/include/libxml2 -I/usr/include/glibmm-2.4 -I/usr/lib/glibmm-2.4/include -I/usr/include/sigc++-2.0 -I/usr/lib/sigc++-2.0/include -I/usr/include/glib-2.0 -I/usr/lib/glib-2.0/include  -lxml++-2.6 -lxml2 -lglibmm-2.4 -lgobject-2.0 -lsigc-2.0 -lglib-2.0  
   dbus-1 ............ 1.6.4
     flags ........... -I/usr/include/dbus-1.0 -I/usr/lib/dbus-1.0/include  -ldbus-1  
 uname -a...
   Linux andre 3.5.3-1-ARCH #1 SMP PREEMPT Sun Aug 26 08:15:06 UTC 2012 i686 GNU/Linux
 Hardware...
   Host controllers:
15:00.0 FireWire (IEEE 1394) [0c00]: Texas Instruments XIO2200A IEEE-1394a-2000 Controller (PHY/Link) [104c:8235] (rev 01) (prog-if 10 [OHCI])
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV+ VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap+ 66MHz+ UDF- FastB2B- ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 32 (500ns min, 1000ns max), Cache Line Size: 64 bytes
	Interrupt: pin A routed to IRQ 19
	Region 0: Memory at f6204000 (32-bit, non-prefetchable) [size=2K]
	Region 1: Memory at f6200000 (32-bit, non-prefetchable) [size=16K]
	Capabilities: <access denied>
	Kernel driver in use: firewire_ohci

1a:00.0 FireWire (IEEE 1394) [0c00]: O2 Micro, Inc. 1394 OHCI Compliant Host Controller [1217:10f7] (rev 01) (prog-if 10 [OHCI])
	Subsystem: Dell Device [1028:02bc]
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 0, Cache Line Size: 64 bytes
	Interrupt: pin A routed to IRQ 16
	Region 0: Memory at fe400000 (32-bit, non-prefetchable) [size=4K]
	Region 1: Memory at fe402000 (32-bit, non-prefetchable) [size=2K]
	Capabilities: <access denied>
	Kernel driver in use: firewire_ohci

   CPU info:
Architecture:          i686
CPU op-mode(s):        32-bit, 64-bit
Byte Order:            Little Endian
CPU(s):                2
On-line CPU(s) list:   0,1
Thread(s) per core:    1
Core(s) per socket:    2
Socket(s):             1
Vendor ID:             GenuineIntel
CPU family:            6
Model:                 23
Stepping:              10
CPU MHz:               1600.000
BogoMIPS:              4390.00
Virtualization:        VT-x
L1d cache:             32K
L1i cache:             32K
L2 cache:              2048K
 Configuration...
  IRQ information
Hardware Interrupts:
--------------------
 IRQ    0: PID:  None, count:     [79797, 89786], Sched None (priority None), drivers: ['timer']
 IRQ    1: PID:  None, count:             [5, 4], Sched None (priority None), drivers: ['i8042']
 IRQ    8: PID:  None, count:             [0, 1], Sched None (priority None), drivers: ['rtc0']
 IRQ    9: PID:  None, count:         [489, 484], Sched None (priority None), drivers: ['acpi']
 IRQ   12: PID:  None, count:           [67, 43], Sched None (priority None), drivers: ['i8042']
 IRQ   16: PID:  None, count:             [3, 5], Sched None (priority None), drivers: ['uhci_hcd:usb2', 'mmc0', 'firewire_ohci']
 IRQ   18: PID:  None, count:     [22327, 21798], Sched None (priority None), drivers: ['uhci_hcd:usb7', 'b43']
 IRQ   19: PID:  None, count:   [421756, 412386], Sched None (priority None), drivers: ['ehci_hcd:usb1', 'uhci_hcd:usb4', 'uhci_hcd:usb6', 'ata_piix', 'ata_piix', 'firewire_ohci']
 IRQ   21: PID:  None, count:       [5139, 5155], Sched None (priority None), drivers: ['uhci_hcd:usb3']
 IRQ   23: PID:  None, count:         [266, 213], Sched None (priority None), drivers: ['uhci_hcd:usb5', 'ehci_hcd:usb8']
 IRQ   46: PID:  None, count:             [0, 0], Sched None (priority None), drivers: ['eth0']
 IRQ   47: PID:  None, count:         [723, 729], Sched None (priority None), drivers: ['snd_hda_intel']
 IRQ   48: PID:  None, count:     [27132, 27154], Sched None (priority None), drivers: ['i915']

Software Interrupts:
--------------------


=== REPORT ===
FireWire kernel drivers:

The new FireWire kernel stack is loaded. 
If running a kernel earlier than 2.6.37 and problems are experienced, either 
try with the old Firewire kernel stack or upgrade to a newer kernel 
(preferrably 2.6.37 or later).

ffado-mixer solo (i killed it, because it would repeat forever)

[andre@andre ~]$ ffado-mixer
19:13:49 dbus             DEBUG    connecting to: Updated on /org/ffado/Control/DeviceManager (server: org.ffado.Control)
19:13:50 dbus             DEBUG    Received update signal
19:13:50 panelmanager     DEBUG    devlistUpdate
19:13:50 dbus             DEBUG    Received post-update signal
19:13:50 panelmanager     DEBUG    devlistPostUpdate
19:13:50 panelmanager     DEBUG    PanelManager::updatePanels()
19:13:50 panelmanager     DEBUG    going to add 00130e0401404efb
19:13:50 panelmanager     DEBUG    Adding device 0: 00130e0401404efb
19:13:50 panelmanager     DEBUG     Found (00130e0401404efb, 130E, 5) Focusrite SAFFIRE_PRO_40
19:13:50 registration     DEBUG    version/GUID combo already registered
19:13:50 panelmanager     DEBUG    devlistPostUpdate failed (10)
19:13:52 panelmanager     DEBUG    PanelManager::updatePanels()
19:13:52 panelmanager     DEBUG    devlistPostUpdate failed (9)
19:13:54 panelmanager     DEBUG    PanelManager::updatePanels()
19:13:54 panelmanager     DEBUG    devlistPostUpdate failed (8)
19:13:56 panelmanager     DEBUG    PanelManager::updatePanels()
19:13:56 panelmanager     DEBUG    devlistPostUpdate failed (7)
19:13:58 panelmanager     DEBUG    PanelManager::updatePanels()
19:13:58 panelmanager     DEBUG    devlistPostUpdate failed (6)
19:14:00 panelmanager     DEBUG    PanelManager::updatePanels()
19:14:00 panelmanager     DEBUG    devlistPostUpdate failed (5)
19:14:02 panelmanager     DEBUG    PanelManager::updatePanels()
19:14:02 panelmanager     DEBUG    devlistPostUpdate failed (4)
19:14:04 panelmanager     DEBUG    PanelManager::updatePanels()
19:14:04 panelmanager     DEBUG    devlistPostUpdate failed (3)
19:14:06 panelmanager     DEBUG    PanelManager::updatePanels()
19:14:06 panelmanager     DEBUG    devlistPostUpdate failed (2)
19:14:08 panelmanager     DEBUG    PanelManager::updatePanels()
19:14:08 panelmanager     DEBUG    devlistPostUpdate failed (1)
19:14:10 panelmanager     DEBUG    devlistPostUpdate failed completely
19:14:10 panelmanager     DEBUG    PanelManager::updatePanels()
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/ffado/panelmanager.py", line 344, in updatePanels
    nbDevices = self.devmgr.getNbDevices()
  File "/usr/lib/python2.7/site-packages/ffado/dbus_util.py", line 265, in getNbDevices
    return self.iface.getNbElements()
  File "/usr/lib/python2.7/site-packages/dbus/proxies.py", line 145, in __call__
    **keywords)
  File "/usr/lib/python2.7/site-packages/dbus/connection.py", line 651, in call_blocking
    message, timeout)
dbus.exceptions.DBusException: org.freedesktop.DBus.Error.ServiceUnknown: The name :1.51 was not provided by any .service files
19:14:10 panelmanager     ERROR    The communication with ffado-dbus-server was lost.
19:14:10 dbus             DEBUG    connecting to: Updated on /org/ffado/Control/DeviceManager (server: org.ffado.Control)
19:14:10 dbus             DEBUG    Received update signal
19:14:10 panelmanager     DEBUG    devlistUpdate
19:14:10 dbus             DEBUG    Received post-update signal
19:14:10 panelmanager     DEBUG    devlistPostUpdate
19:14:10 panelmanager     DEBUG    PanelManager::updatePanels()
19:14:10 panelmanager     DEBUG    going to add 00130e0401404efb
19:14:10 panelmanager     DEBUG    Adding device 0: 00130e0401404efb
19:14:10 panelmanager     DEBUG     Found (00130e0401404efb, 130E, 5) Focusrite SAFFIRE_PRO_40
19:14:10 registration     DEBUG    version/GUID combo already registered
19:14:11 panelmanager     DEBUG    devlistPostUpdate failed (10)
19:14:13 panelmanager     DEBUG    PanelManager::updatePanels()
19:14:13 panelmanager     DEBUG    devlistPostUpdate failed (9)
19:14:15 panelmanager     DEBUG    PanelManager::updatePanels()
19:14:15 panelmanager     DEBUG    devlistPostUpdate failed (8)
19:14:17 panelmanager     DEBUG    PanelManager::updatePanels()
19:14:17 panelmanager     DEBUG    devlistPostUpdate failed (7)
19:14:19 panelmanager     DEBUG    PanelManager::updatePanels()
19:14:19 panelmanager     DEBUG    devlistPostUpdate failed (6)
19:14:21 panelmanager     DEBUG    PanelManager::updatePanels()
19:14:21 panelmanager     DEBUG    devlistPostUpdate failed (5)
19:14:23 panelmanager     DEBUG    PanelManager::updatePanels()
19:14:23 panelmanager     DEBUG    devlistPostUpdate failed (4)
19:14:25 panelmanager     DEBUG    PanelManager::updatePanels()
19:14:25 panelmanager     DEBUG    devlistPostUpdate failed (3)
19:14:27 panelmanager     DEBUG    PanelManager::updatePanels()
19:14:27 panelmanager     DEBUG    devlistPostUpdate failed (2)
19:14:29 panelmanager     DEBUG    PanelManager::updatePanels()
19:14:29 panelmanager     DEBUG    devlistPostUpdate failed (1)
19:14:31 panelmanager     DEBUG    devlistPostUpdate failed completely
19:14:31 panelmanager     DEBUG    PanelManager::updatePanels()
python2: Fatal IO error 11 (Resource temporarily unavailable) on X server :0.0.
[andre@andre ~]$ 

ffado-dbus-server

-----------------------------------------------
FFADO Control DBUS service
Part of the FFADO project -- www.ffado.org
Version: 2.999.0-2205M
(C) 2008, Pieter Palmers
This program comes with ABSOLUTELY NO WARRANTY.
-----------------------------------------------

1347297330764520:  (ffado-dbus-server.cpp)[ 270] main:  Discovering devices...
1347297330768203: Debug (ieee1394service.cpp)[ 363] initialize: The raw1394_read_cycle_timer_and_clock call and/or the CLOCK_MONOTONIC
1347297330768225: Debug (ieee1394service.cpp)[ 364] initialize: clock source is not available.
1347297330768229: Debug (ieee1394service.cpp)[ 365] initialize: Fallback to raw1394_read_cycle_timer.
1347297330768235: Debug (ieee1394service.cpp)[ 366] initialize: FFADO may be susceptible to NTP-induced clock discontinuities.
1347297330768238: Debug (ieee1394service.cpp)[ 367] initialize: If this is an issue, upgrade libraw1394 to version 2.1.0 or later and/or
1347297330768244: Debug (ieee1394service.cpp)[ 368] initialize: kernel 2.6.36 or later.
1347297330770495: Debug (devicemanager.cpp)[ 358] discover: Starting discovery...
1347297330968044: Debug (Configuration.cpp)[ 163] showSetting:   Group: (null)
1347297330968130: Debug (Configuration.cpp)[ 185] showSetting:     vendorid = 4878 (0x0000130E)
1347297330968179: Debug (Configuration.cpp)[ 185] showSetting:     modelid = 5 (0x00000005)
1347297330968221: Debug (Configuration.cpp)[ 209] showSetting:     vendorname = Focusrite
1347297330968345: Debug (Configuration.cpp)[ 209] showSetting:     modelname = Saffire PRO 40
1347297330968359: Debug (Configuration.cpp)[ 185] showSetting:     driver = 20 (0x00000014)
1347297330968375: Debug (Configuration.cpp)[ 209] showSetting:     mixer = Saffire_Dice
1347297330968507: Debug (Configuration.cpp)[ 163] showSetting:   Group: (null)
1347297330968527: Debug (Configuration.cpp)[ 185] showSetting:     vendorid = 4878 (0x0000130E)
1347297330968536: Debug (Configuration.cpp)[ 185] showSetting:     modelid = 5 (0x00000005)
1347297330968550: Debug (Configuration.cpp)[ 209] showSetting:     vendorname = Focusrite
1347297330968558: Debug (Configuration.cpp)[ 209] showSetting:     modelname = Saffire PRO 40
1347297330968574: Debug (Configuration.cpp)[ 185] showSetting:     driver = 20 (0x00000014)
1347297330968582: Debug (Configuration.cpp)[ 209] showSetting:     mixer = Saffire_Dice
1347297330968688: Debug (Configuration.cpp)[ 163] showSetting:   Group: (null)
1347297330968701: Debug (Configuration.cpp)[ 185] showSetting:     vendorid = 4878 (0x0000130E)
1347297330968714: Debug (Configuration.cpp)[ 185] showSetting:     modelid = 5 (0x00000005)
1347297330968722: Debug (Configuration.cpp)[ 209] showSetting:     vendorname = Focusrite
1347297330968743: Debug (Configuration.cpp)[ 209] showSetting:     modelname = Saffire PRO 40
1347297330968751: Debug (Configuration.cpp)[ 185] showSetting:     driver = 20 (0x00000014)
1347297330969345: Debug (Configuration.cpp)[ 209] showSetting:     mixer = Saffire_Dice
1347297330969461: Debug (Configuration.cpp)[ 163] showSetting:   Group: (null)
1347297330969483: Debug (Configuration.cpp)[ 185] showSetting:     vendorid = 4878 (0x0000130E)
1347297330969492: Debug (Configuration.cpp)[ 185] showSetting:     modelid = 5 (0x00000005)
1347297330969505: Debug (Configuration.cpp)[ 209] showSetting:     vendorname = Focusrite
1347297330969512: Debug (Configuration.cpp)[ 209] showSetting:     modelname = Saffire PRO 40
1347297330969528: Debug (Configuration.cpp)[ 185] showSetting:     driver = 20 (0x00000014)
1347297330969536: Debug (Configuration.cpp)[ 209] showSetting:     mixer = Saffire_Dice
1347297330969752: Debug (Configuration.cpp)[ 163] showSetting:   Group: (null)
1347297330969765: Debug (Configuration.cpp)[ 185] showSetting:     vendorid = 4878 (0x0000130E)
1347297330969780: Debug (Configuration.cpp)[ 185] showSetting:     modelid = 5 (0x00000005)
1347297330969788: Debug (Configuration.cpp)[ 209] showSetting:     vendorname = Focusrite
1347297330969804: Debug (Configuration.cpp)[ 209] showSetting:     modelname = Saffire PRO 40
1347297330969812: Debug (Configuration.cpp)[ 185] showSetting:     driver = 20 (0x00000014)
1347297330969914: Debug (Configuration.cpp)[ 209] showSetting:     mixer = Saffire_Dice
1347297330970211: Debug (devicemanager.cpp)[ 620] discover: driver found for device 0
1347297330970334: Debug (Configuration.cpp)[ 163] showSetting:   Group: (null)
1347297330970347: Debug (Configuration.cpp)[ 185] showSetting:     vendorid = 4878 (0x0000130E)
1347297330970361: Debug (Configuration.cpp)[ 185] showSetting:     modelid = 5 (0x00000005)
1347297330970369: Debug (Configuration.cpp)[ 209] showSetting:     vendorname = Focusrite
1347297330970385: Debug (Configuration.cpp)[ 209] showSetting:     modelname = Saffire PRO 40
1347297330970393: Debug (Configuration.cpp)[ 185] showSetting:     driver = 20 (0x00000014)
1347297330970410: Debug (Configuration.cpp)[ 209] showSetting:     mixer = Saffire_Dice
1347297331040189: Warning (dice_eap.cpp)[1791] read: No routes found. Base 0x7, offset 0x4000
1347297331074415: Warning (dice_eap.cpp)[1226] updateNameCache: What is this function about?
1347297331175517: Debug (devicemanager.cpp)[ 657] discover: discovery of node 0 on port 0 done...
1347297331175597: Debug (devicemanager.cpp)[ 665] discover: Discovery finished...
1347297331175639: Debug (devicemanager.cpp)[1269] showDeviceInfo: ===== Device Manager =====
1347297331175685: Debug (Element.cpp)[ 121] show: Element DeviceManager
1347297331175718: Debug (devicemanager.cpp)[1277] showDeviceInfo: --- IEEE1394 Service  0 ---
Iso handler info:
Dumping IsoHandlerManager Stream handler information...
 State: 2
1347297331175865: Debug (devicemanager.cpp)[1287] showDeviceInfo: --- Device  0 ---
1347297331175906: Debug (dice_avdevice.cpp)[ 650] showDevice: Device is a DICE device
1347297331175936: Debug (ffadodevice.cpp)[ 215] showDevice: Attached to port.......: 0 (/dev/fw2)
1347297331175975: Debug (ffadodevice.cpp)[ 216] showDevice: Node...................: 0
1347297331176002: Debug (ffadodevice.cpp)[ 218] showDevice: Vendor name............: Focusrite
1347297331176039: Debug (ffadodevice.cpp)[ 220] showDevice: Model name.............: SAFFIRE_PRO_40
1347297331176074: Debug (ffadodevice.cpp)[ 222] showDevice: GUID...................: 00130e0401404efb
1347297331176123: Debug (ffadodevice.cpp)[ 227] showDevice: Assigned ID....: 00130e0401404efb
1347297331176158:  (dice_avdevice.cpp)[ 653] showDevice:  DICE Parameter Space info:
1347297331176194:  (dice_avdevice.cpp)[ 654] showDevice:   Global  : offset=0x0028 size=0360
1347297331176220:  (dice_avdevice.cpp)[ 655] showDevice:   TX      : offset=0x0190 size=0568
1347297331176255:  (dice_avdevice.cpp)[ 656] showDevice:                 nb=   2 size=0280
1347297331176285:  (dice_avdevice.cpp)[ 657] showDevice:   RX      : offset=0x03C8 size=1128
1347297331176319:  (dice_avdevice.cpp)[ 658] showDevice:                 nb=   2 size=0280
1347297331176348:  (dice_avdevice.cpp)[ 659] showDevice:   UNUSED1 : offset=0x0830 size=0016
1347297331176382:  (dice_avdevice.cpp)[ 660] showDevice:   UNUSED2 : offset=0x0000 size=0000
1347297331176412:  (dice_avdevice.cpp)[ 662] showDevice:  Global param space:
1347297331178535:  (dice_avdevice.cpp)[ 665] showDevice:   Owner            : 0xE0000000FFC1FFFF
1347297331180151:  (dice_avdevice.cpp)[ 668] showDevice:   Notification     : 0x00000040
1347297331183181:  (dice_avdevice.cpp)[ 671] showDevice:   Nick name        : SaffirePro40arry
1347297331184548:  (dice_avdevice.cpp)[ 675] showDevice:   Clock Select     : 0x01 0x0C
1347297331186161:  (dice_avdevice.cpp)[ 679] showDevice:   Enable           : true
1347297331188278:  (dice_avdevice.cpp)[ 683] showDevice:   Clock Status     : locked 0x01
1347297331189919:  (dice_avdevice.cpp)[ 686] showDevice:   Extended Status  : 0x000000C0
1347297331191357:  (dice_avdevice.cpp)[ 689] showDevice:   Samplerate       : 0x0000AC44 (44100)
1347297331192816:  (dice_avdevice.cpp)[ 692] showDevice:   Version          : 0x01000400
1347297331194318:  (dice_avdevice.cpp)[ 701] showDevice:   Version          : 0x01000400 (1.0.4.0)
1347297331195676:  (dice_avdevice.cpp)[ 704] showDevice:   Clock caps       : 0x1325001E
1347297331198835:  (dice_avdevice.cpp)[ 707] showDevice:   Clock sources    :
1347297331198863:  (dice_avdevice.cpp)[ 713] showDevice:     SPDIF
1347297331198871:  (dice_avdevice.cpp)[ 713] showDevice:     AES34
1347297331198886:  (dice_avdevice.cpp)[ 713] showDevice:     SPDIF-OPT
1347297331198891:  (dice_avdevice.cpp)[ 713] showDevice:     AES78
1347297331198899:  (dice_avdevice.cpp)[ 713] showDevice:     AES-ANY
1347297331198904:  (dice_avdevice.cpp)[ 713] showDevice:     ADAT
1347297331198918:  (dice_avdevice.cpp)[ 713] showDevice:     ADAT_AUX
1347297331198924:  (dice_avdevice.cpp)[ 713] showDevice:     Word Clock
1347297331198956:  (dice_avdevice.cpp)[ 713] showDevice:     Unused
1347297331199049:  (dice_avdevice.cpp)[ 713] showDevice:     Unused
1347297331199059:  (dice_avdevice.cpp)[ 713] showDevice:     Unused
1347297331199064:  (dice_avdevice.cpp)[ 713] showDevice:     Unused
1347297331199072:  (dice_avdevice.cpp)[ 713] showDevice:     Internal
1347297331199078:  (dice_avdevice.cpp)[ 716] showDevice:  TX param space:
1347297331199091:  (dice_avdevice.cpp)[ 717] showDevice:   Nb of xmit        : 2
1347297331199181:  (dice_avdevice.cpp)[ 719] showDevice:   Transmitter 0:
1347297331200398:  (dice_avdevice.cpp)[ 722] showDevice:    ISO channel       :   0
1347297331201806:  (dice_avdevice.cpp)[ 724] showDevice:    ISO speed         :   2
1347297331203457:  (dice_avdevice.cpp)[ 727] showDevice:    Nb audio channels :  10
1347297331204766:  (dice_avdevice.cpp)[ 729] showDevice:    Nb midi channels  :   1
1347297331206383:  (dice_avdevice.cpp)[ 732] showDevice:    AC3 caps          : 0x00000000
1347297331208502:  (dice_avdevice.cpp)[ 734] showDevice:    AC3 enable        : 0x00000000
1347297331210441:  (dice_avdevice.cpp)[ 737] showDevice:    Channel names     :
1347297331210458:  (dice_avdevice.cpp)[ 742] showDevice:      IP 1
1347297331210473:  (dice_avdevice.cpp)[ 742] showDevice:      IP 2
1347297331210479:  (dice_avdevice.cpp)[ 742] showDevice:      IP 3
1347297331210492:  (dice_avdevice.cpp)[ 742] showDevice:      IP 4
1347297331210498:  (dice_avdevice.cpp)[ 742] showDevice:      IP 5
1347297331210510:  (dice_avdevice.cpp)[ 742] showDevice:      IP 6
1347297331210516:  (dice_avdevice.cpp)[ 742] showDevice:      IP 7
1347297331210525:  (dice_avdevice.cpp)[ 742] showDevice:      IP 8
1347297331210530:  (dice_avdevice.cpp)[ 742] showDevice:      SPDIF L
1347297331210541:  (dice_avdevice.cpp)[ 742] showDevice:      SPDIF R
1347297331210549:  (dice_avdevice.cpp)[ 719] showDevice:   Transmitter 1:
1347297331211817:  (dice_avdevice.cpp)[ 722] showDevice:    ISO channel       :   1
1347297331213400:  (dice_avdevice.cpp)[ 724] showDevice:    ISO speed         :   2
1347297331214768:  (dice_avdevice.cpp)[ 727] showDevice:    Nb audio channels :  10
1347297331216370:  (dice_avdevice.cpp)[ 729] showDevice:    Nb midi channels  :   0
1347297331218599:  (dice_avdevice.cpp)[ 732] showDevice:    AC3 caps          : 0x00000000
1347297331220164:  (dice_avdevice.cpp)[ 734] showDevice:    AC3 enable        : 0x00000000
1347297331221850:  (dice_avdevice.cpp)[ 737] showDevice:    Channel names     :
1347297331221901:  (dice_avdevice.cpp)[ 742] showDevice:      ADAT 1
1347297331221940:  (dice_avdevice.cpp)[ 742] showDevice:      ADAT 2
1347297331221978:  (dice_avdevice.cpp)[ 742] showDevice:      ADAT 3
1347297331222009:  (dice_avdevice.cpp)[ 742] showDevice:      ADAT 4
1347297331222034:  (dice_avdevice.cpp)[ 742] showDevice:      ADAT 5
1347297331222072:  (dice_avdevice.cpp)[ 742] showDevice:      ADAT 6
1347297331222098:  (dice_avdevice.cpp)[ 742] showDevice:      ADAT 7
1347297331222240:  (dice_avdevice.cpp)[ 742] showDevice:      ADAT 8
1347297331222271:  (dice_avdevice.cpp)[ 742] showDevice:      Loop 1
1347297331222307:  (dice_avdevice.cpp)[ 742] showDevice:      Loop 2
1347297331222339:  (dice_avdevice.cpp)[ 746] showDevice:  RX param space:
1347297331222374:  (dice_avdevice.cpp)[ 747] showDevice:   Nb of recv        : 2
1347297331222409:  (dice_avdevice.cpp)[ 749] showDevice:   Receiver 0:
1347297331223642:  (dice_avdevice.cpp)[ 752] showDevice:    ISO channel       :   2
1347297331225267:  (dice_avdevice.cpp)[ 754] showDevice:    Sequence start    :   0
1347297331226644:  (dice_avdevice.cpp)[ 757] showDevice:    Nb audio channels :  12
1347297331229187:  (dice_avdevice.cpp)[ 759] showDevice:    Nb midi channels  :   1
1347297331230601:  (dice_avdevice.cpp)[ 762] showDevice:    AC3 caps          : 0x00000000
1347297331232177:  (dice_avdevice.cpp)[ 764] showDevice:    AC3 enable        : 0x00000000
1347297331233799:  (dice_avdevice.cpp)[ 767] showDevice:    Channel names     :
1347297331233815:  (dice_avdevice.cpp)[ 772] showDevice:      Mon 1
1347297331233829:  (dice_avdevice.cpp)[ 772] showDevice:      Mon 2
1347297331233834:  (dice_avdevice.cpp)[ 772] showDevice:      Line 3
1347297331233843:  (dice_avdevice.cpp)[ 772] showDevice:      Line 4
1347297331233848:  (dice_avdevice.cpp)[ 772] showDevice:      Line 5
1347297331233861:  (dice_avdevice.cpp)[ 772] showDevice:      Line 6
1347297331233867:  (dice_avdevice.cpp)[ 772] showDevice:      Line 7
1347297331233879:  (dice_avdevice.cpp)[ 772] showDevice:      Line 8
1347297331233884:  (dice_avdevice.cpp)[ 772] showDevice:      Line 9
1347297331233893:  (dice_avdevice.cpp)[ 772] showDevice:      Line 10
1347297331233898:  (dice_avdevice.cpp)[ 772] showDevice:      SPDIF L
1347297331233910:  (dice_avdevice.cpp)[ 772] showDevice:      SPDIF R
1347297331233918:  (dice_avdevice.cpp)[ 749] showDevice:   Receiver 1:
1347297331235377:  (dice_avdevice.cpp)[ 752] showDevice:    ISO channel       :   3
1347297331236751:  (dice_avdevice.cpp)[ 754] showDevice:    Sequence start    :   0
1347297331239353:  (dice_avdevice.cpp)[ 757] showDevice:    Nb audio channels :   8
1347297331240624:  (dice_avdevice.cpp)[ 759] showDevice:    Nb midi channels  :   0
1347297331242247:  (dice_avdevice.cpp)[ 762] showDevice:    AC3 caps          : 0x00000000
1347297331243633:  (dice_avdevice.cpp)[ 764] showDevice:    AC3 enable        : 0x00000000
1347297331245479:  (dice_avdevice.cpp)[ 767] showDevice:    Channel names     :
1347297331245604:  (dice_avdevice.cpp)[ 772] showDevice:      ADAT 1
1347297331245623:  (dice_avdevice.cpp)[ 772] showDevice:      ADAT 2
1347297331245629:  (dice_avdevice.cpp)[ 772] showDevice:      ADAT 3
1347297331245638:  (dice_avdevice.cpp)[ 772] showDevice:      ADAT 4
1347297331245644:  (dice_avdevice.cpp)[ 772] showDevice:      ADAT 5
1347297331245653:  (dice_avdevice.cpp)[ 772] showDevice:      ADAT 6
1347297331245657:  (dice_avdevice.cpp)[ 772] showDevice:      ADAT 7
1347297331245675:  (dice_avdevice.cpp)[ 772] showDevice:      ADAT 8
1347297331245706: Debug (devicemanager.cpp)[1290] showDeviceInfo: Clock sync sources:
1347297331252672: Debug (devicemanager.cpp)[1299] showDeviceInfo:  Type: AES               , Id:  0, Valid: 1, Active: 0, Locked 0, Slipping: 0, Description: SPDIF
1347297331252696: Debug (devicemanager.cpp)[1299] showDeviceInfo:  Type: AES               , Id:  2, Valid: 1, Active: 0, Locked 0, Slipping: 0, Description: SPDIF-OPT
1347297331252717: Debug (devicemanager.cpp)[1299] showDeviceInfo:  Type: ADAT              , Id:  5, Valid: 1, Active: 0, Locked 0, Slipping: 0, Description: ADAT
1347297331252726: Debug (devicemanager.cpp)[1299] showDeviceInfo:  Type: Compound Syt Match, Id:  8, Valid: 1, Active: 0, Locked 1, Slipping: 0, Description: Unused
1347297331252743: Debug (devicemanager.cpp)[1299] showDeviceInfo:  Type: Compound Syt Match, Id:  9, Valid: 1, Active: 0, Locked 1, Slipping: 0, Description: Unused
1347297331252751: Debug (devicemanager.cpp)[1299] showDeviceInfo:  Type: Internal          , Id: 12, Valid: 1, Active: 1, Locked 1, Slipping: 0, Description: Internal
1347297331263204:  (ffado-dbus-server.cpp)[ 328] main: DBUS service running
1347297331263267:  (ffado-dbus-server.cpp)[ 329] main: press ctrl-c to stop it & exit
1347297331263306: Debug (ffado-dbus-server.cpp)[ 332] main: dispatching...
/*FFADO-MIXER IS LAUNCHED HERE - AndreeeCZ*/
process 1325: arguments to dbus_message_iter_append_basic() were incorrect, assertion "_dbus_check_is_valid_utf8 (*string_p)" failed in file dbus-message.c line 2598.
This is normally a bug in some application using the D-Bus library.
  D-Bus not built with -rdynamic so unable to print a backtrace
Aborted

ffado-mixer when ffado-dbus-server is ran separately

[andre@andre ~]$ ffado-mixer
19:18:21 dbus             DEBUG    connecting to: Updated on /org/ffado/Control/DeviceManager (server: org.ffado.Control)
19:18:21 panelmanager     DEBUG    PanelManager::updatePanels()
19:18:21 panelmanager     DEBUG    going to add 00130e0401404efb
19:18:21 panelmanager     DEBUG    Adding device 0: 00130e0401404efb
19:18:21 panelmanager     DEBUG     Found (00130e0401404efb, 130E, 5) Focusrite SAFFIRE_PRO_40
19:18:21 registration     DEBUG    version/GUID combo already registered
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/ffado/panelmanager.py", line 386, in updatePanels
    self.addPanel(idx)
  File "/usr/lib/python2.7/site-packages/ffado/panelmanager.py", line 276, in addPanel
    globalmixer.initValues()
  File "/usr/lib/python2.7/site-packages/ffado/mixer/globalmixer.py", line 107, in initValues
    self.txtNickname.setText( self.nickname.text() )
  File "/usr/lib/python2.7/site-packages/ffado/dbus_util.py", line 350, in text
    return self.iface.getValue()
  File "/usr/lib/python2.7/site-packages/dbus/proxies.py", line 70, in __call__
    return self._proxy_method(*args, **keywords)
  File "/usr/lib/python2.7/site-packages/dbus/proxies.py", line 145, in __call__
    **keywords)
  File "/usr/lib/python2.7/site-packages/dbus/connection.py", line 651, in call_blocking
    message, timeout)
dbus.exceptions.DBusException: org.freedesktop.DBus.Error.NoReply: Message did not receive a reply (timeout by message bus)
19:18:23 panelmanager     ERROR    The communication with ffado-dbus-server was lost.
19:18:23 dbus             DEBUG    connecting to: Updated on /org/ffado/Control/DeviceManager (server: org.ffado.Control)
19:18:23 dbus             DEBUG    Received update signal
19:18:23 panelmanager     DEBUG    devlistUpdate
19:18:23 dbus             DEBUG    Received post-update signal
19:18:23 panelmanager     DEBUG    devlistPostUpdate
19:18:23 panelmanager     DEBUG    PanelManager::updatePanels()
19:18:23 panelmanager     DEBUG    going to add 00130e0401404efb
19:18:23 panelmanager     DEBUG    Adding device 0: 00130e0401404efb
19:18:24 panelmanager     DEBUG     Found (00130e0401404efb, 130E, 5) Focusrite SAFFIRE_PRO_40
19:18:24 registration     DEBUG    version/GUID combo already registered
19:18:24 panelmanager     DEBUG    devlistPostUpdate failed (10)
19:18:26 panelmanager     DEBUG    PanelManager::updatePanels()
19:18:26 panelmanager     DEBUG    devlistPostUpdate failed (9)
19:18:28 panelmanager     DEBUG    PanelManager::updatePanels()
19:18:28 panelmanager     DEBUG    devlistPostUpdate failed (8)
19:18:30 panelmanager     DEBUG    PanelManager::updatePanels()
19:18:30 panelmanager     DEBUG    devlistPostUpdate failed (7)
19:18:32 panelmanager     DEBUG    PanelManager::updatePanels()
19:18:32 panelmanager     DEBUG    devlistPostUpdate failed (6)
19:18:34 panelmanager     DEBUG    PanelManager::updatePanels()
19:18:34 panelmanager     DEBUG    devlistPostUpdate failed (5)
19:18:36 panelmanager     DEBUG    PanelManager::updatePanels()
19:18:36 panelmanager     DEBUG    devlistPostUpdate failed (4)
19:18:38 panelmanager     DEBUG    PanelManager::updatePanels()
19:18:38 panelmanager     DEBUG    devlistPostUpdate failed (3)
19:18:40 panelmanager     DEBUG    PanelManager::updatePanels()
19:18:40 panelmanager     DEBUG    devlistPostUpdate failed (2)
19:18:42 panelmanager     DEBUG    PanelManager::updatePanels()
19:18:42 panelmanager     DEBUG    devlistPostUpdate failed (1)
19:18:44 panelmanager     DEBUG    devlistPostUpdate failed completely
19:18:44 panelmanager     DEBUG    PanelManager::updatePanels()
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/ffado/panelmanager.py", line 344, in updatePanels
    nbDevices = self.devmgr.getNbDevices()
  File "/usr/lib/python2.7/site-packages/ffado/dbus_util.py", line 265, in getNbDevices
    return self.iface.getNbElements()
  File "/usr/lib/python2.7/site-packages/dbus/proxies.py", line 145, in __call__
    **keywords)
  File "/usr/lib/python2.7/site-packages/dbus/connection.py", line 651, in call_blocking
    message, timeout)
dbus.exceptions.DBusException: org.freedesktop.DBus.Error.ServiceUnknown: The name :1.61 was not provided by any .service files
19:18:44 panelmanager     ERROR    The communication with ffado-dbus-server was lost.
19:18:44 dbus             DEBUG    connecting to: Updated on /org/ffado/Control/DeviceManager (server: org.ffado.Control)
python2: Fatal IO error 11 (Resource temporarily unavailable) on X server :0.0.
/*KILLED IT - AndreeeCZ*/

Change History

09/28/12 08:18:22 changed by andreeecz

I have caught the bull by the horns!

Thread 1 (Thread 0xb74d4700 (LWP 4188)):
#0  0xb7fdd424 in __kernel_vsyscall ()
#1  0xb76165df in raise () from /usr/lib/libc.so.6
#2  0xb7617ec3 in abort () from /usr/lib/libc.so.6
#3  0xb7c45f35 in ?? () from /usr/lib/libdbus-1.so.3
#4  0xb7c3b271 in ?? () from /usr/lib/libdbus-1.so.3
#5  0xb7c2ba74 in dbus_message_iter_append_basic () from /usr/lib/libdbus-1.so.3
#6  0xb7c7623b in ?? () from /usr/lib/libdbus-c++-1.so.0
#7  0xb7c766af in DBus::MessageIter::append_string(char const*) ()
---Type <return> to continue, or q <return> to quit---
   from /usr/lib/libdbus-c++-1.so.0
#8  0x08057813 in operator<< (iter=..., val=
    "SaffirePro40arry\267l$\r\b@\355\372\267l$\r\btR\357\377\277\350\061\b\b\002\310\361\267N\310\361\267\063") at /usr/include/dbus-c++-1/dbus-c++/types.h:382
#9  0x0805b450 in org::ffado::Control::Element::Text_adaptor::_getValue_stub (this=
    0x80b1240, call=...) at support/dbus/controlserver-glue.h:929
#10 0x08069c73 in DBus::Callback<org::ffado::Control::Element::Text_adaptor, DBus::Message, DBus::CallMessage const&>::call (this=0x80b1150, param=...)
    at /usr/include/dbus-c++-1/dbus-c++/util.h:283
#11 0xb7c87ff4 in ?? () from /usr/lib/libdbus-c++-1.so.0
Backtrace stopped: previous frame inner to this frame (corrupt stack?)

This is a gdb output on ffado-dbus-server crash. From here, it is pretty clear whats happening: Former name of the device was <something>ScarryBarry?, which can be seen from the leftovers in the call. I have set the nickname to SaffirePro?40. Now ffado doesnt seem to be able to handle this, as the nickname clearly contains lots of non-utf stuff! :)

09/29/12 06:10:55 changed by jwoithe

Your analysis of the dump looks reasonable. Phil posted this followup to the ffado-devel mailing list earlier today:

Strange, since getnickname (at least for Focusrite) returns no more than 16 characters; and ffado-dbus-server effectively returns a 16 characters nickname (your previous report). Which way did you use to change the nickname at first ?

It's hard to determine quite where the problem is occurring. It certainly appears that a buffer containing the nickname is not being zero-terminated correctly somewhere; but where that might be is far from clear.

I am far from familiar with the way the DICE devices work. A casual glance through the source code suggests that the nickname string as returned by the device may not in fact be explicitly NULL terminated before being passed onto other areas of FFADO. If this is the case, then trouble will occur if the device itself does not return a NULL-terminated nickname.

EAP::readRegBlock() clearly just reads "length" bytes values into the "data" buffer. In SaffirePro?40::getNickname(), this is essentially all that's being done. Therefore if the Nickname doesn't contain a terminating NULL byte, the memory pointed to by "name" in SaffirePro?40::getNickname() won't be either, unless by chance the "name" array included a zero somewhere. When the result is converted to a std::string, there's no telling how long the resulting string would be.

Working on the assumption that the device has space for a nickname up to 16 bytes in length, I've pushed r2237 into trunk. This does two things. First and foremost it ensures correct NULL termination of the nickname returned by SaffirePro?40::getNickname(). Secondly, it ensures that at most 16 characters are sent to the device when setting the nickname via SaffirePro?40::setNickname(). If my assumptions are correct and this proves to fix the problem as documented by the above dump, the changes will need to be propagated to the other Saffire sub-drivers as well.

09/30/12 16:56:29 changed by jwoithe

A more complete fix for this issue is in r2238 for the Pro40 (r2239 and r2240 contain similar fixes for the Pro14 and Pro24 respectively). Thanks to Philippe Carriere for providing these addtional patches. Could you please re-test this issue with trunk revision r2238 or later and report whether it resolves the problem for you?

10/30/12 04:29:50 changed by jwoithe

  • status changed from new to closed.
  • resolution set to fixed.

It is my understanding that this bug should be fixed for the Pro14, Pro24 and Pro40 as of r2240 and later. If the problem recurs with a later version of FFADO please reopen this ticket.