Ticket #247: 44.1k

File 44.1k, 153.4 kB (added by sireasoning, 14 years ago)

ctrl-c at 44.1k

Line 
1
2 root@ubuntu-studio:/home/sczjd# jackd -R -P70 -dfirewire -r44100 -p1024 -n4 -v 6
3 jackd 0.118.0
4 Copyright 2001-2009 Paul Davis, Stephane Letz, Jack O'Quinn, Torben Hohn and others.
5 jackd comes with ABSOLUTELY NO WARRANTY
6 This is free software, and you are welcome to redistribute it
7 under certain conditions; see the file COPYING for details
8
9 no message buffer overruns
10 JACK compiled with System V SHM support.
11 jack: 5402:245841142534 engine.c:jack_get_fifo_fd:3572: /dev/shm/jack-0/default/jack-ack-fifo-5402-0
12 jack: 5402:245841142582 engine.c:jack_get_fifo_fd:3616: opened engine->fifo[0] == 7 (/dev/shm/jack-0/default/jack-ack-fifo-5402-0)
13 loading driver ..
14 jack: 5405:245841149663 engine.c:jack_server_thread:1480: acquiring graph read lock
15 jack: 5405:245841149720 engine.c:jack_server_thread:1517: release graph lock
16 jack: 5402:245841172516 clientengine.c:jack_client_by_name:346: acquiring graph read lock
17 jack: 5402:245841172536 clientengine.c:jack_client_by_name:357: release graph lock
18 jack: 5402:245841172552 clientengine.c:setup_client:634: acquiring graph write lock
19 jack: 5402:245841172560 clientengine.c:setup_client:641: release graph lock
20 jack: 5402:245841173897 engine.c:jack_deliver_event_to_all:2417: acquiring graph read lock
21 jack: 5402:245841173907 engine.c:jack_deliver_event:2460: delivering event (type 2)
22 jack: 5402:245841173911 engine.c:jack_deliver_event:2473: client firewire_pcm is still alive
23 jack: 5402:245841173913 engine.c:jack_deliver_event:2637: event delivered
24 jack: 5402:245841173915 engine.c:jack_deliver_event_to_all:2423: release graph lock
25 jack: 5402:245841175027 engine.c:jack_deliver_event_to_all:2417: acquiring graph read lock
26 jack: 5402:245841175036 engine.c:jack_deliver_event:2460: delivering event (type 2)
27 jack: 5402:245841175040 engine.c:jack_deliver_event:2473: client firewire_pcm is still alive
28 jack: 5402:245841175041 engine.c:jack_deliver_event:2637: event delivered
29 jack: 5402:245841175042 engine.c:jack_deliver_event_to_all:2423: release graph lock
30 jack: 5402:245841175044 engine.c:jack_driver_buffer_size:529: acquiring graph write lock
31 jack: 5402:245841175045 engine.c:jack_driver_buffer_size:534: release graph lock
32 jack: 5402:245841175046 engine.c:jack_deliver_event_to_all:2417: acquiring graph read lock
33 245841175071:  (ffado.cpp)[  92] ffado_streaming_init: libffado 2.999.0-1784 built Jan  5 2010 16:32:47
34 jack: 5402:245841175048 engine.c:jack_deliver_event:2460: delivering event (type 0)
35 jack: 5402:245841175049 engine.c:jack_deliver_event:2473: client firewire_pcm is still alive
36 jack: 5402:245841175055 engine.c:jack_deliver_event:2637: event delivered
37 jack: 5402:245841175056 engine.c:jack_deliver_event_to_all:2423: release graph lock
38 245841175191: Debug (Element.cpp)[ 129] setVerboseLevel: Setting verbose level to 6...
39 245841175200: Debug (StreamProcessorManager.cpp)[1569] setVerboseLevel: Setting verbose level to 6...
40 245841175206: Debug (devicemanager.cpp)[1260] setVerboseLevel: Setting verbose level to 6...
41 245841175209: Debug (ffado.cpp)[ 119] ffado_streaming_init: Starting with realtime scheduling, base priority 70
42 245841175216: Debug (DeviceStringParser.cpp)[ 284] isValidString: isvalid? hw:0
43 245841175226: Debug (devicemanager.cpp)[ 233] addSpecString: Adding spec string hw:0
44 245841175233: Debug (DeviceStringParser.cpp)[ 253] parseString: parse: hw:0
45 245841175236: Debug (DeviceStringParser.cpp)[ 258] parseString:  left: hw:0
46 245841175239: Debug (DeviceStringParser.cpp)[  56] parse: parse: hw:0
47 245841175257: Debug (ffado.cpp)[ 148] ffado_streaming_init: setting slave mode to 0
48 245841175269: Debug (ffado.cpp)[ 154] ffado_streaming_init: setting snoop mode to 0
49 245841175374: Debug (Configuration.cpp)[  63] openFile: Could not open file: ~/.ffado/configuration
50 245841176079: Debug (devicemanager.cpp)[ 194] initialize: Found 1 firewire adapters (ports)
51 245841176097: Debug (IsoHandlerManager.cpp)[1143] setVerboseLevel: Setting verbose level to 6...
52 245841176104: Debug (ieee1394service.cpp)[1567] setVerboseLevel: Setting verbose level to 6...
53 245841176112: Debug (ieee1394service.cpp)[ 422] setThreadParameters: Switching IsoManager to (rt=1, prio=70)
54 245841176119: Debug (IsoHandlerManager.cpp)[ 528] setThreadParameters: (0x1bc8680) switch to: (rt=1, prio=70)...
55 245841176152: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting ieee1394.isomanager.prio_increase
56 245841176187: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting ieee1394.isomanager.prio_increase
57 245841176196: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'ieee1394.isomanager.prio_increase' not found
58 245841176207: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting ieee1394.isomanager.prio_increase_xmit
59 245841176220: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting ieee1394.isomanager.prio_increase_xmit
60 245841176226: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'ieee1394.isomanager.prio_increase_xmit' not found
61 245841176236: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting ieee1394.isomanager.prio_increase_recv
62 245841176249: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting ieee1394.isomanager.prio_increase_recv
63 245841176254: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'ieee1394.isomanager.prio_increase_recv' not found
64 245841176257: Debug (ieee1394service.cpp)[ 428] setThreadParameters: Switching CycleTimerHelper to (rt=1, prio=1)
65 245841176260: Debug (CycleTimerHelper.cpp)[ 231] setThreadParameters: (0x1bc8700) switch to: (rt=1, prio=1)...
66 245841176283: Debug (Watchdog.cpp)[ 200] start: (0x1bc88f0) Starting watchdog...
67 245841176289: Debug (Watchdog.cpp)[ 201] start: Create hartbeat task/thread for 0x1bc88f0...
68 245841176293: Debug (Watchdog.cpp)[ 215] start:  hartbeat task: 0x1bc8a50, thread 0x1bc8ac0...
69 245841176296: Debug (Watchdog.cpp)[ 217] start: Create check task/thread for 0x1bc88f0...
70 245841176299: Debug (Watchdog.cpp)[ 231] start:  check task: 0x1bc8b40, thread 0x1bc8bb0...
71 245841187292: Debug (Watchdog.cpp)[ 249] start: (0x1bc88f0) Watchdog running...
72 245841206241: Debug (ieee1394service.cpp)[ 331] initialize: This system supports the raw1394_read_cycle_timer call, using it.
73 245841206448: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting ieee1394.min_split_timeout_usecs
74 245841206477: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting ieee1394.min_split_timeout_usecs
75 245841206487: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'ieee1394.min_split_timeout_usecs' not found
76 245841206495: Debug (ieee1394service.cpp)[ 964] getSplitTimeoutUsecs: reading SPLIT_TIMEOUT on node 0x1...
77 245841206533: Debug (ieee1394service.cpp)[ 971] getSplitTimeoutUsecs:  READ HI: 0x01000000
78 245841206555: Debug (ieee1394service.cpp)[ 978] getSplitTimeoutUsecs:  READ LO: 0x00000000
79 245841206565: Debug (ieee1394service.cpp)[ 372] initialize: Minimum SPLIT_TIMEOUT: 1000000. Current: 1000000
80 245841206572: Debug (CycleTimerHelper.cpp)[ 116] Start: Start 0x1bc8700...
81 245841206576: Debug (CycleTimerHelper.cpp)[ 149] initValues: (0x1bc8700) Init values...
82 245841206580: Debug (CycleTimerHelper.cpp)[ 156] initValues: Read CTR...
83 245841206586: Debug (CycleTimerHelper.cpp)[ 167] initValues:  read : CTR:  3416254608, local:  1262749395593975
84 245841206591: Debug (CycleTimerHelper.cpp)[ 173] initValues:   ctr   : 0xCB9FE890  2502619280 (101s 6654cy 2192ticks)
85 245841206595: Debug (CycleTimerHelper.cpp)[ 179] initValues: requesting DLL re-init...
86 245841207661: Debug (CycleTimerHelper.cpp)[ 308] initDLL:  (0x1bc8700) First run
87 245841207669: Debug (CycleTimerHelper.cpp)[ 310] initDLL:   DLL bandwidth: 0.500000 Hz (rel: 0.100000)
88 245841207682: Debug (CycleTimerHelper.cpp)[ 313] initDLL:   usecs/update: 200000, ticks/update: 4915200, m_dll_e2: 4915200.000000
89 245841207689: Debug (CycleTimerHelper.cpp)[ 316] initDLL:   usecs current: 1262749395595048.000000, next: 1262749395795048.000000
90 245841207697: Debug (CycleTimerHelper.cpp)[ 319] initDLL:   ticks current: 2502645653.000000, next: 2507560853.000000
91 245841207708: Debug (CycleTimerHelper.cpp)[ 188] initValues: ready...
92 245841207719: Debug (Watchdog.cpp)[ 281] registerThread: (0x1bc88f0) Adding thread 0x1bcb6a0
93 245841214986: Debug (IsoHandlerManager.cpp)[1143] setVerboseLevel: Setting verbose level to 6...
94 245841215115: Debug (IsoHandlerManager.cpp)[ 569] init: Initializing ISO manager 0x1bc8680...
95 245841214986: Debug (CycleTimerHelper.cpp)[ 195] Init: Initialize 0x1bc8700...
96 245841215177: Debug (ieee1394service.cpp)[1225] addBusResetHandler: Adding busreset handler (0x1bcb850)
97 245841215228: Debug (CycleTimerHelper.cpp)[ 393] Execute: (0x1bc8700) have to retry CTR read, diff unrealistic: diff: -642896434, max: +/- 3072 (try: 10) 0
98 245841215319: Debug (CycleTimerHelper.cpp)[ 308] initDLL:  (0x1bc8700) First run
99 245841215329: Debug (CycleTimerHelper.cpp)[ 310] initDLL:   DLL bandwidth: 0.500000 Hz (rel: 0.100000)
100 245841215349: Debug (CycleTimerHelper.cpp)[ 313] initDLL:   usecs/update: 200000, ticks/update: 4915200, m_dll_e2: 4915200.000000
101 245841215357: Debug (CycleTimerHelper.cpp)[ 316] initDLL:   usecs current: 1262749395602706.000000, next: 1262749395802706.000000
102 245841215365: Debug (CycleTimerHelper.cpp)[ 319] initDLL:   ticks current: 2502833829.000000, next: 2507749029.000000
103 245841215405: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting ieee1394.isomanager.prio_increase
104 245841215462: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting ieee1394.isomanager.prio_increase
105 245841215473: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'ieee1394.isomanager.prio_increase' not found
106 245841215491: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting ieee1394.isomanager.prio_increase_xmit
107 245841215512: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting ieee1394.isomanager.prio_increase_xmit
108 245841215521: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'ieee1394.isomanager.prio_increase_xmit' not found
109 245841215537: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting ieee1394.isomanager.prio_increase_recv
110 245841215558: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting ieee1394.isomanager.prio_increase_recv
111 245841215567: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'ieee1394.isomanager.prio_increase_recv' not found
112 245841215583: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting ieee1394.isomanager.isotask_activity_timeout_usecs
113 245841215605: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting ieee1394.isomanager.isotask_activity_timeout_usecs
114 245841215615: Debug (Configuration.cpp)[ 268] getValueForSetting: path 'ieee1394.isomanager.isotask_activity_timeout_usecs' not found
115 245841215619: Debug (IsoHandlerManager.cpp)[ 590] init: Create iso thread for 0x1bc8680 transmit...
116 245841215624: Debug (IsoHandlerManager.cpp)[ 445] setVerboseLevel: Setting verbose level to 6...
117 245841215633: Debug (Thread.h)[ 124] setVerboseLevel: (ISOXMT) Setting verbose level to 6...
118 245841215637: Debug (IsoHandlerManager.cpp)[ 609] init: Create iso thread for 0x1bc8680 receive...
119 245841215641: Debug (IsoHandlerManager.cpp)[ 445] setVerboseLevel: Setting verbose level to 6...
120 245841215645: Debug (Thread.h)[ 124] setVerboseLevel: (ISORCV) Setting verbose level to 6...
121 245841215650: Debug (Watchdog.cpp)[ 281] registerThread: (0x1bc88f0) Adding thread 0x1bcbab0
122 245841215665: Debug (Watchdog.cpp)[ 281] registerThread: (0x1bc88f0) Adding thread 0x1bcbcd0
123 245841215675: Debug (PosixThread.cpp)[ 101] Start: (ISOXMT) Create RT thread 0x1bcbab0 with priority 71
124 245841222906: Debug (PosixThread.cpp)[  78] ThreadHandler: (ISOXMT) ThreadHandler: start 0x1bcbab0
125 245841222906: Debug (PosixThread.cpp)[ 101] Start: (ISORCV) Create RT thread 0x1bcbcd0 with priority 69
126 245841232332: Debug (PosixThread.cpp)[  78] ThreadHandler: (ISORCV) ThreadHandler: start 0x1bcbcd0
127 245841232332: Debug (ieee1394service.cpp)[ 422] setThreadParameters: Switching IsoManager to (rt=1, prio=70)
128 245841232981: Debug (IsoHandlerManager.cpp)[ 528] setThreadParameters: (0x1bc8680) switch to: (rt=1, prio=70)...
129 245841233037: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting ieee1394.isomanager.prio_increase
130 245841233056: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting ieee1394.isomanager.prio_increase
131 245841233066: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'ieee1394.isomanager.prio_increase' not found
132 245841233079: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting ieee1394.isomanager.prio_increase_xmit
133 245841233096: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting ieee1394.isomanager.prio_increase_xmit
134 245841233105: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'ieee1394.isomanager.prio_increase_xmit' not found
135 245841233118: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting ieee1394.isomanager.prio_increase_recv
136 245841233145: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting ieee1394.isomanager.prio_increase_recv
137 245841233155: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'ieee1394.isomanager.prio_increase_recv' not found
138 245841233159: Debug (PosixThread.cpp)[ 208] AcquireRealTime: (ISOXMT, 0x1bcbab0) Aquire realtime, prio 71
139 245841233166: Debug (PosixThread.cpp)[ 208] AcquireRealTime: (ISORCV, 0x1bcbcd0) Aquire realtime, prio 69
140 245841233170: Debug (ieee1394service.cpp)[ 428] setThreadParameters: Switching CycleTimerHelper to (rt=1, prio=1)
141 245841233174: Debug (CycleTimerHelper.cpp)[ 231] setThreadParameters: (0x1bc8700) switch to: (rt=1, prio=1)...
142 245841233178: Debug (PosixThread.cpp)[ 208] AcquireRealTime: (CTRHLP, 0x1bcb6a0) Aquire realtime, prio 1
143 245841233184: Debug (ieee1394service.cpp)[1666] setThreadParameters: (0x1bcb0b0) switch to: (rt=1, prio=70)...
144 245841233187: Debug (PosixThread.cpp)[ 208] AcquireRealTime: (ARMRT, 0x1bcb0f0) Aquire realtime, prio 70
145 245841233212: Debug (ieee1394service.cpp)[1225] addBusResetHandler: Adding busreset handler (0x1bcbda0)
146 245841233224: Debug (devicemanager.cpp)[ 358] discover: Starting discovery...
147 245841233241: Debug (Element.cpp)[ 129] setVerboseLevel: Setting verbose level to 6...
148 245841233253: Debug (StreamProcessorManager.cpp)[1569] setVerboseLevel: Setting verbose level to 6...
149 245841233264: Debug (Thread.h)[ 124] setVerboseLevel: (ISOXMT) Setting verbose level to 6...
150 245841233271: Debug (IsoHandlerManager.cpp)[ 445] setVerboseLevel: Setting verbose level to 6...
151 245841233274: Debug (Thread.h)[ 124] setVerboseLevel: (ISORCV) Setting verbose level to 6...
152 245841233277: Debug (IsoHandlerManager.cpp)[ 445] setVerboseLevel: Setting verbose level to 6...
153 245841233280: Debug (IsoHandlerManager.cpp)[1143] setVerboseLevel: Setting verbose level to 6...
154 245841233283: Debug (ieee1394service.cpp)[1567] setVerboseLevel: Setting verbose level to 6...
155 245841233286: Debug (devicemanager.cpp)[1260] setVerboseLevel: Setting verbose level to 6...
156 245841233292: Debug (devicemanager.cpp)[ 385] discover: Probing node 0...
157 245841292622: Debug (devicemanager.cpp)[ 385] discover: Probing node 1...
158 245841292641: Debug (devicemanager.cpp)[ 388] discover: Skipping local node (1)...
159 245841292662: Debug (DeviceStringParser.cpp)[ 391] show: DeviceStringParser: 0x1bc75c0
160 245841292667: Debug (DeviceStringParser.cpp)[ 218] show: string: hw:0
161 245841292671: Debug (DeviceStringParser.cpp)[ 221] show: type: eBusNode
162 245841292673: Debug (DeviceStringParser.cpp)[ 223] show:  Port: 0, Node: -1
163 245841292683: Debug (devicemanager.cpp)[ 560] discover: Probing node 0...
164 245841352469: Debug (configrom.cpp)[ 562] printConfigRomDebug: Config ROM
165 245841352483: Debug (configrom.cpp)[ 563] printConfigRomDebug:  Current Node Id:        0
166 245841352487: Debug (configrom.cpp)[ 564] printConfigRomDebug:  GUID:                   0x0001F20000015A02
167 245841352491: Debug (configrom.cpp)[ 565] printConfigRomDebug:  Vendor Name:           
168 245841352495: Debug (configrom.cpp)[ 566] printConfigRomDebug:  Model Name:             
169 245841352498: Debug (configrom.cpp)[ 567] printConfigRomDebug:  Node Vendor ID:         0x0001f2
170 245841352501: Debug (configrom.cpp)[ 568] printConfigRomDebug:  Model Id:               0x00102800
171 245841352504: Debug (configrom.cpp)[ 569] printConfigRomDebug:  Unit Specifier ID:      0x0001f2
172 245841352507: Debug (configrom.cpp)[ 570] printConfigRomDebug:  Unit version:           0x00000005
173 245841352511: Debug (configrom.cpp)[ 571] printConfigRomDebug:  ISO resource manager:   0
174 245841352513: Debug (configrom.cpp)[ 572] printConfigRomDebug:  Cycle master capable:   1
175 245841352516: Debug (configrom.cpp)[ 573] printConfigRomDebug:  Bus manager capable:    0
176 245841352519: Debug (configrom.cpp)[ 574] printConfigRomDebug:  Cycle clock accuracy:   0
177 245841352522: Debug (configrom.cpp)[ 576] printConfigRomDebug:  Max rec:                1 (max asy payload: 4 bytes)
178 245841352533: Debug (DeviceStringParser.cpp)[ 162] match: match 0x1bdf4b0 (0001f20000015a02)
179 245841352537: Debug (DeviceStringParser.cpp)[ 175] match: (eBusNode) device matches device string hw:0
180 245841352541: Debug (devicemanager.cpp)[1109] getDriverForDevice: Probing for supported device...
181 245841352544: Debug (devicemanager.cpp)[1032] getDriverForDeviceDo: Trying BeBoB...
182 245841352579: Debug (Configuration.cpp)[ 394] getDeviceSetting:   temporary has no device definitions
183 245841352684: Debug (devicemanager.cpp)[1039] getDriverForDeviceDo: Trying ECHO Audio FireWorks...
184 245841352699: Debug (Configuration.cpp)[ 394] getDeviceSetting:   temporary has no device definitions
185 245841352764: Debug (devicemanager.cpp)[1046] getDriverForDeviceDo: Trying Oxford FW90x...
186 245841352781: Debug (Configuration.cpp)[ 394] getDeviceSetting:   temporary has no device definitions
187 245841352846: Debug (devicemanager.cpp)[1061] getDriverForDeviceDo: Trying Generic AV/C...
188 245841352862: Debug (Configuration.cpp)[ 394] getDeviceSetting:   temporary has no device definitions
189 245841352924: Debug (devicemanager.cpp)[1068] getDriverForDeviceDo: Trying Motu...
190 245841352971: Debug (Element.cpp)[ 253] addElement: Adding Element ConfigRom to 0001f20000015a02
191 245841352992: Debug (Element.cpp)[ 253] addElement: Adding Element Generic to 0001f20000015a02
192 245841353007: Debug (Element.cpp)[ 253] addElement: Adding Element ClockSelect to Generic
193 245841353045: Debug (Element.cpp)[ 253] addElement: Adding Element SamplerateSelect to Generic
194 245841353089: Debug (Element.cpp)[ 253] addElement: Adding Element Nickname to Generic
195 245841353106: Debug (Element.cpp)[ 253] addElement: Adding Element StreamingStatus to Generic
196 245841353113: Debug (devicemanager.cpp)[1112] getDriverForDevice:  found supported device...
197 245841353119: Debug (Element.cpp)[ 129] setVerboseLevel: Setting verbose level to 6...
198 245841353122: Debug (devicemanager.cpp)[ 620] discover: driver found for device 0
199 245841353125: Debug (ffadodevice.cpp)[ 216] setVerboseLevel: Setting verbose level to 6...
200 245841353128: Debug (Element.cpp)[ 129] setVerboseLevel: Setting verbose level to 6...
201 245841353132: Debug (motu_avdevice.cpp)[ 447] discover: found MOTU 896HD
202 245841353231: Debug (motu_mixer.cpp)[ 292] buildMixer: Building a MOTU mixer...
203 245841353239: Debug (motu_mixer.cpp)[ 357] destroyMixer: destroy mixer...
204 245841353242: Debug (motu_mixer.cpp)[ 360] destroyMixer: no mixer to destroy...
205 245841353252: Debug (Element.cpp)[ 253] addElement: Adding Element fader to Mixer
206 245841353260: Debug (Element.cpp)[ 253] addElement: Adding Element pan to Mixer
207 245841353269: Debug (Element.cpp)[ 253] addElement: Adding Element solo to Mixer
208 245841353281: Debug (Element.cpp)[ 253] addElement: Adding Element mute to Mixer
209 245841353368: Debug (Element.cpp)[ 253] addElement: Adding Element Mix1/Mix_fader to Mixer
210 245841353381: Debug (Element.cpp)[ 253] addElement: Adding Element Mix1/Mix_mute to Mixer
211 245841353389: Debug (Element.cpp)[ 253] addElement: Adding Element Mix1/Mix_dest to Mixer
212 245841353405: Debug (Element.cpp)[ 253] addElement: Adding Element Mix2/Mix_fader to Mixer
213 245841353472: Debug (Element.cpp)[ 253] addElement: Adding Element Mix2/Mix_mute to Mixer
214 245841353487: Debug (Element.cpp)[ 253] addElement: Adding Element Mix2/Mix_dest to Mixer
215 245841353499: Debug (Element.cpp)[ 253] addElement: Adding Element Mix3/Mix_fader to Mixer
216 245841353508: Debug (Element.cpp)[ 253] addElement: Adding Element Mix3/Mix_mute to Mixer
217 245841353519: Debug (Element.cpp)[ 253] addElement: Adding Element Mix3/Mix_dest to Mixer
218 245841353527: Debug (Element.cpp)[ 253] addElement: Adding Element Mix4/Mix_fader to Mixer
219 245841353539: Debug (Element.cpp)[ 253] addElement: Adding Element Mix4/Mix_mute to Mixer
220 245841353550: Debug (Element.cpp)[ 253] addElement: Adding Element Mix4/Mix_dest to Mixer
221 245841353566: Debug (Element.cpp)[ 253] addElement: Adding Element Mainout_fader to Mixer
222 245841353580: Debug (Element.cpp)[ 253] addElement: Adding Element Phones_fader to Mixer
223 245841353593: Debug (Element.cpp)[ 253] addElement: Adding Element Control/Phones_src to Mixer
224 245841353606: Debug (Element.cpp)[ 253] addElement: Adding Element Control/OpticalIn_mode to Mixer
225 245841353614: Debug (Element.cpp)[ 253] addElement: Adding Element Control/OpticalOut_mode to Mixer
226 245841353627: Debug (Element.cpp)[ 253] addElement: Adding Element Control/Meter_peakhold_time to Mixer
227 245841353640: Debug (Element.cpp)[ 253] addElement: Adding Element Control/Meter_cliphold_time to Mixer
228 245841353648: Debug (Element.cpp)[ 253] addElement: Adding Element Control/Meter_aesebu_src to Mixer
229 245841353660: Debug (Element.cpp)[ 253] addElement: Adding Element Control/Meter_src to Mixer
230 245841353677: Debug (Element.cpp)[ 253] addElement: Adding Element Info/Model to Mixer
231 245841353685: Debug (Element.cpp)[ 253] addElement: Adding Element Info/IsStreaming to Mixer
232 245841353696: Debug (Element.cpp)[ 253] addElement: Adding Element Info/SampleRate to Mixer
233 245841353704: Debug (Element.cpp)[ 253] addElement: Adding Element Mixer to 0001f20000015a02
234 245841353717: Debug (Element.cpp)[ 253] addElement: Adding Element Control to 0001f20000015a02
235 245841353725: Debug (devicemanager.cpp)[ 630] discover: discovery successful
236 245841353728: Debug (devicemanager.cpp)[ 649] discover: No cached version of AVC model created
237 245841353738: Debug (Element.cpp)[ 253] addElement: Adding Element 0001f20000015a02 to DeviceManager
238 245841353743: Debug (devicemanager.cpp)[ 657] discover: discovery of node 0 on port 0 done...
239 245841353748: Debug (devicemanager.cpp)[ 560] discover: Probing node 1...
240 245841353752: Debug (devicemanager.cpp)[ 563] discover: Skipping local node (1)...
241 245841353755: Debug (devicemanager.cpp)[ 665] discover: Discovery finished...
242 245841353762: Debug (DeviceStringParser.cpp)[ 162] match: match 0x1bdf4b0 (0001f20000015a02)
243 245841353765: Debug (DeviceStringParser.cpp)[ 175] match: (eBusNode) device matches device string hw:0
244 245841353775: Debug (devicemanager.cpp)[ 684] discover: Mapping 0001f20000015a02 to position 0...
245 245841354012: Debug (ffadodevice.cpp)[ 176] setId: Set id to dev0...
246 245841354029: Debug (devicemanager.cpp)[1265] showDeviceInfo: ===== Device Manager =====
247 245841354037: Debug (Element.cpp)[ 121] show: Element DeviceManager
248 245841354041: Debug (devicemanager.cpp)[1273] showDeviceInfo: --- IEEE1394 Service  0 ---
249 245841354051: Debug (ieee1394service.cpp)[1582] show: Port:  0
250 245841354056: Debug (ieee1394service.cpp)[1583] show:  Name: ohci1394
251 245841354059: Debug (ieee1394service.cpp)[1585] show:  CycleTimerHelper: 0x1bc8700, IsoManager: 0x1bc8680, WatchDog: 0x1bc88f0
252 245841354063: Debug (ieee1394service.cpp)[1590] show:  Time: 02506242878 (101s 7834cy 0830ticks)
253 Iso handler info:
254 Dumping IsoHandlerManager Stream handler information...
255  State: 2
256 245841354072: Debug (devicemanager.cpp)[1283] showDeviceInfo: --- Device  0 ---
257 245841354076: Debug (motu_avdevice.cpp)[ 854] showDevice: MOTU 896HD at node 0
258 245841354080: Debug (devicemanager.cpp)[1286] showDeviceInfo: Clock sync sources:
259 245841354098: Debug (devicemanager.cpp)[1295] showDeviceInfo:  Type: Internal          , Id:  0, Valid: 1, Active: 1, Locked 1, Slipping: 0, Description: Internal sync
260 245841354103: Debug (devicemanager.cpp)[1295] showDeviceInfo:  Type: ADAT              , Id:  1, Valid: 1, Active: 1, Locked 1, Slipping: 0, Description: ADAT optical
261 245841354107: Debug (devicemanager.cpp)[1295] showDeviceInfo:  Type: SPDIF             , Id:  2, Valid: 1, Active: 1, Locked 1, Slipping: 0, Description: SPDIF/Toslink
262 245841354111: Debug (devicemanager.cpp)[1295] showDeviceInfo:  Type: Erratic type      , Id:  3, Valid: 0, Active: 0, Locked 0, Slipping: 0, Description: SMPTE
263 245841354116: Debug (devicemanager.cpp)[1295] showDeviceInfo:  Type: WordClock         , Id:  4, Valid: 1, Active: 1, Locked 1, Slipping: 0, Description: Wordclock
264 245841354120: Debug (devicemanager.cpp)[1295] showDeviceInfo:  Type: ADAT              , Id:  5, Valid: 1, Active: 1, Locked 1, Slipping: 0, Description: ADAT 9-pin
265 245841354124: Debug (devicemanager.cpp)[1295] showDeviceInfo:  Type: AES               , Id:  7, Valid: 1, Active: 1, Locked 1, Slipping: 0, Description: AES/EBU
266 245841354152: Debug (devicemanager.cpp)[ 801] initStreaming: Locking device (0x1be0ce0)
267 245841354160: Debug (devicemanager.cpp)[ 809] initStreaming: Setting samplerate to 44100 for (0x1be0ce0)
268 245841392682: Debug (motu_avdevice.cpp)[ 866] prepare: Preparing MotuDevice...
269 245841408335: Debug (ieee1394service.cpp)[1266] allocateIsoChannelGeneric: Allocating ISO channel using generic method...
270 245841408445: Debug (ieee1394service.cpp)[1266] allocateIsoChannelGeneric: Allocating ISO channel using generic method...
271 245841408551: Debug (motu_avdevice.cpp)[ 911] prepare: recv channel = 0, send channel = 1
272 245841408622: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting streaming.spm.recv_sp_dll_bw
273 245841408648: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting streaming.spm.recv_sp_dll_bw
274 245841408657: Debug (Configuration.cpp)[ 289] getValueForSetting: path 'streaming.spm.recv_sp_dll_bw' not found
275 245841408673: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting streaming.spm.xmit_sp_dll_bw
276 245841408692: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting streaming.spm.xmit_sp_dll_bw
277 245841408700: Debug (Configuration.cpp)[ 289] getValueForSetting: path 'streaming.spm.xmit_sp_dll_bw' not found
278 245841408715: Debug (Configuration.cpp)[ 394] getDeviceSetting:   temporary has no device definitions
279 245841408788: Debug (Configuration.cpp)[ 359] getValueForDeviceSetting: device 1F2/102800 not found
280 245841408806: Debug (Configuration.cpp)[ 394] getDeviceSetting:   temporary has no device definitions
281 245841408869: Debug (Configuration.cpp)[ 359] getValueForDeviceSetting: device 1F2/102800 not found
282 245841408889: Debug (StreamProcessor.cpp)[1931] setVerboseLevel: Setting verbose level to 6...
283 245841408898: Debug (IsoHandlerManager.cpp)[ 711] registerStream: Registering Receive stream 0x1be50e0
284 245841408904: Debug (IsoHandlerManager.cpp)[ 936] pruneHandlers: enter...
285 245841408924: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting ieee1394.isomanager.iso_receive_mode
286 245841408944: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting ieee1394.isomanager.iso_receive_mode
287 245841408952: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'ieee1394.isomanager.iso_receive_mode' not found
288 245841408967: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting ieee1394.isomanager.bufferfill_mode_threshold
289 245841408986: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting ieee1394.isomanager.bufferfill_mode_threshold
290 245841408995: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'ieee1394.isomanager.bufferfill_mode_threshold' not found
291 245841409060: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting ieee1394.isomanager.min_interrupts_per_period
292 245841409081: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting ieee1394.isomanager.min_interrupts_per_period
293 245841409091: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'ieee1394.isomanager.min_interrupts_per_period' not found
294 245841409106: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting ieee1394.isomanager.max_nb_buffers_recv
295 245841409126: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting ieee1394.isomanager.max_nb_buffers_recv
296 245841409135: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'ieee1394.isomanager.max_nb_buffers_recv' not found
297 245841409188: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting ieee1394.isomanager.min_packetsize_recv
298 245841409245: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting ieee1394.isomanager.min_packetsize_recv
299 245841409256: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'ieee1394.isomanager.min_packetsize_recv' not found
300 245841409262: Debug (IsoHandlerManager.cpp)[ 762] registerStream: Using bufferfill mode (auto) [186, 64]
301 245841409265: Debug (IsoHandlerManager.cpp)[ 808] registerStream:  creating IsoRecvHandler
302 245841409270: Debug (IsoHandlerManager.cpp)[1420] setVerboseLevel: Setting verbose level to 6...
303 245841409274: Debug (IsoHandlerManager.cpp)[1426] registerStream: registering stream (0x1be50e0)
304 245841409277: Debug (IsoHandlerManager.cpp)[ 668] registerHandler: enter...
305 245841409280: Debug (IsoHandlerManager.cpp)[1420] setVerboseLevel: Setting verbose level to 6...
306 245841409288: Debug (IsoHandlerManager.cpp)[  88] requestShadowMapUpdate: (0x1bcb910) enter
307 245841409292: Debug (IsoHandlerManager.cpp)[  93] requestShadowMapUpdate: (0x1bcb910) exit
308 245841409295: Debug (IsoHandlerManager.cpp)[  88] requestShadowMapUpdate: (0x1bcbb30) enter
309 245841409298: Debug (IsoHandlerManager.cpp)[  93] requestShadowMapUpdate: (0x1bcbb30) exit
310 245841409301: Debug (IsoHandlerManager.cpp)[ 887] registerStream:  registered stream (0x1be50e0) with handler (0x1be4da0)
311 245841409309: Debug (IsoHandlerManager.cpp)[ 891] registerStream:  1 streams, 1 handlers registered
312 245841409313: Debug (StreamProcessorManager.cpp)[ 226] registerProcessor: Registering processor (0x1be50e0)
313 245841409317: Debug (StreamProcessor.cpp)[1931] setVerboseLevel: Setting verbose level to 6...
314 245841409322: Debug (PortManager.cpp)[ 236] addPortManagerUpdateHandler: Adding PortManagerUpdate handler (0x1be4d30)
315 245841409331: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
316 245841409336: Debug (motu_avdevice.cpp)[ 956] prepare: Adding ports to receive processor
317 245841409351: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_cap_Mix-L, type: 0, dir: 1
318 245841409365: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be4d30)
319 245841409374: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
320 245841409382: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_cap_Mix-R, type: 0, dir: 1
321 245841409388: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be4d30)
322 245841409391: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
323 245841409398: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_cap_Analog1, type: 0, dir: 1
324 245841409403: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be4d30)
325 245841409406: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
326 245841409413: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_cap_Analog2, type: 0, dir: 1
327 245841409418: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be4d30)
328 245841409421: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
329 245841409427: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_cap_Analog3, type: 0, dir: 1
330 245841409432: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be4d30)
331 245841409436: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
332 245841409442: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_cap_Analog4, type: 0, dir: 1
333 245841409448: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be4d30)
334 245841409451: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
335 245841409456: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_cap_Analog5, type: 0, dir: 1
336 245841409461: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be4d30)
337 245841409465: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
338 245841409471: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_cap_Analog6, type: 0, dir: 1
339 245841409476: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be4d30)
340 245841409479: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
341 245841409485: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_cap_Analog7, type: 0, dir: 1
342 245841409491: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be4d30)
343 245841409495: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
344 245841409502: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_cap_Analog8, type: 0, dir: 1
345 245841409508: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be4d30)
346 245841409511: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
347 245841409518: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_cap_unknown-1, type: 0, dir: 1
348 245841409524: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be4d30)
349 245841409527: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
350 245841409534: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_cap_unknown-2, type: 0, dir: 1
351 245841409540: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be4d30)
352 245841409548: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
353 245841409555: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_cap_AES/EBU1, type: 0, dir: 1
354 245841409562: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be4d30)
355 245841409565: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
356 245841409571: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_cap_AES/EBU2, type: 0, dir: 1
357 245841409578: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be4d30)
358 245841409585: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
359 245841409593: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_cap_MIDI0, type: 1, dir: 1
360 245841409600: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be4d30)
361 245841409604: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
362 245841409613: Debug (StreamProcessor.cpp)[1931] setVerboseLevel: Setting verbose level to 6...
363 245841409621: Debug (IsoHandlerManager.cpp)[ 711] registerStream: Registering Transmit stream 0x1be5a20
364 245841409625: Debug (IsoHandlerManager.cpp)[ 936] pruneHandlers: enter...
365 245841409645: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting ieee1394.isomanager.min_interrupts_per_period
366 245841409665: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting ieee1394.isomanager.min_interrupts_per_period
367 245841409674: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'ieee1394.isomanager.min_interrupts_per_period' not found
368 245841409690: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting ieee1394.isomanager.max_nb_buffers_xmit
369 245841409709: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting ieee1394.isomanager.max_nb_buffers_xmit
370 245841409717: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'ieee1394.isomanager.max_nb_buffers_xmit' not found
371 245841409733: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting ieee1394.isomanager.max_packetsize_xmit
372 245841409751: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting ieee1394.isomanager.max_packetsize_xmit
373 245841409759: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'ieee1394.isomanager.max_packetsize_xmit' not found
374 245841409775: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting ieee1394.isomanager.min_packetsize_xmit
375 245841409793: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting ieee1394.isomanager.min_packetsize_xmit
376 245841409801: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'ieee1394.isomanager.min_packetsize_xmit' not found
377 245841409806: Debug (IsoHandlerManager.cpp)[ 858] registerStream:  creating IsoXmitHandler
378 245841409809: Debug (IsoHandlerManager.cpp)[1420] setVerboseLevel: Setting verbose level to 6...
379 245841409812: Debug (IsoHandlerManager.cpp)[1426] registerStream: registering stream (0x1be5a20)
380 245841409815: Debug (IsoHandlerManager.cpp)[ 668] registerHandler: enter...
381 245841409817: Debug (IsoHandlerManager.cpp)[1420] setVerboseLevel: Setting verbose level to 6...
382 245841409822: Debug (IsoHandlerManager.cpp)[  88] requestShadowMapUpdate: (0x1bcb910) enter
383 245841409826: Debug (IsoHandlerManager.cpp)[  93] requestShadowMapUpdate: (0x1bcb910) exit
384 245841409829: Debug (IsoHandlerManager.cpp)[  88] requestShadowMapUpdate: (0x1bcbb30) enter
385 245841409832: Debug (IsoHandlerManager.cpp)[  93] requestShadowMapUpdate: (0x1bcbb30) exit
386 245841409834: Debug (IsoHandlerManager.cpp)[ 887] registerStream:  registered stream (0x1be5a20) with handler (0x1be5040)
387 245841409839: Debug (IsoHandlerManager.cpp)[ 891] registerStream:  2 streams, 2 handlers registered
388 245841409843: Debug (StreamProcessorManager.cpp)[ 226] registerProcessor: Registering processor (0x1be5a20)
389 245841409847: Debug (StreamProcessor.cpp)[1931] setVerboseLevel: Setting verbose level to 6...
390 245841409851: Debug (PortManager.cpp)[ 236] addPortManagerUpdateHandler: Adding PortManagerUpdate handler (0x1be2120)
391 245841409856: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
392 245841409861: Debug (motu_avdevice.cpp)[1023] prepare: Adding ports to transmit processor
393 245841409869: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_pbk_Phones-L, type: 0, dir: 0
394 245841409875: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be2120)
395 245841409878: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
396 245841409886: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_pbk_Phones-R, type: 0, dir: 0
397 245841409892: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be2120)
398 245841409895: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
399 245841409902: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_pbk_Analog1, type: 0, dir: 0
400 245841409908: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be2120)
401 245841409911: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
402 245841409918: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_pbk_Analog2, type: 0, dir: 0
403 245841409923: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be2120)
404 245841409926: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
405 245841409932: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_pbk_Analog3, type: 0, dir: 0
406 245841409938: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be2120)
407 245841409941: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
408 245841409949: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_pbk_Analog4, type: 0, dir: 0
409 245841409954: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be2120)
410 245841409957: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
411 245841409964: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_pbk_Analog5, type: 0, dir: 0
412 245841409969: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be2120)
413 245841409972: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
414 245841409978: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_pbk_Analog6, type: 0, dir: 0
415 245841409983: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be2120)
416 245841409986: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
417 245841409993: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_pbk_Analog7, type: 0, dir: 0
418 245841409999: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be2120)
419 245841410003: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
420 245841410010: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_pbk_Analog8, type: 0, dir: 0
421 245841410016: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be2120)
422 245841410019: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
423 245841410026: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_pbk_MainOut-L, type: 0, dir: 0
424 245841410032: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be2120)
425 245841410035: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
426 245841410042: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_pbk_MainOut-R, type: 0, dir: 0
427 245841410048: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be2120)
428 245841410051: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
429 245841410058: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_pbk_AES/EBU1, type: 0, dir: 0
430 245841410064: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be2120)
431 245841410067: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
432 245841410075: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_pbk_AES/EBU2, type: 0, dir: 0
433 245841410081: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be2120)
434 245841410084: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
435 245841410091: Debug (PortManager.cpp)[ 100] registerPort: Adding port dev0_pbk_MIDI0, type: 1, dir: 0
436 245841410098: Debug (PortManager.cpp)[ 283] callUpdateHandlers: Calling PortManagerUpdate handler (0x1be2120)
437 245841410101: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
438 245841410111: Debug (StreamProcessorManager.cpp)[ 308] setSyncSource: Setting sync source to (0x1be50e0)
439 jack: 5402:245841411154 engine.c:do_request:1218: got a request of type 1
440 jack: 5402:245841411166 engine.c:jack_port_do_register:3764: acquiring graph write lock
441 jack: 5402:245841411186 engine.c:jack_port_do_register:3852: release graph lock
442 jack: 5402:245841411189 engine.c:do_request:1350: status of request: 0
443 jack: 5402:245841411201 engine.c:do_request:1218: got a request of type 1
444 jack: 5402:245841411204 engine.c:jack_port_do_register:3764: acquiring graph write lock
445 jack: 5402:245841411210 engine.c:jack_port_do_register:3852: release graph lock
446 jack: 5402:245841411212 engine.c:do_request:1350: status of request: 0
447 jack: 5402:245841411217 engine.c:do_request:1218: got a request of type 1
448 jack: 5402:245841411219 engine.c:jack_port_do_register:3764: acquiring graph write lock
449 jack: 5402:245841411225 engine.c:jack_port_do_register:3852: release graph lock
450 jack: 5402:245841411227 engine.c:do_request:1350: status of request: 0
451 jack: 5402:245841411231 engine.c:do_request:1218: got a request of type 1
452 jack: 5402:245841411233 engine.c:jack_port_do_register:3764: acquiring graph write lock
453 jack: 5402:245841411238 engine.c:jack_port_do_register:3852: release graph lock
454 jack: 5402:245841411240 engine.c:do_request:1350: status of request: 0
455 jack: 5402:245841411244 engine.c:do_request:1218: got a request of type 1
456 jack: 5402:245841411246 engine.c:jack_port_do_register:3764: acquiring graph write lock
457 jack: 5402:245841411251 engine.c:jack_port_do_register:3852: release graph lock
458 jack: 5402:245841411253 engine.c:do_request:1350: status of request: 0
459 jack: 5402:245841411257 engine.c:do_request:1218: got a request of type 1
460 jack: 5402:245841411259 engine.c:jack_port_do_register:3764: acquiring graph write lock
461 jack: 5402:245841411264 engine.c:jack_port_do_register:3852: release graph lock
462 jack: 5402:245841411266 engine.c:do_request:1350: status of request: 0
463 jack: 5402:245841411270 engine.c:do_request:1218: got a request of type 1
464 jack: 5402:245841411272 engine.c:jack_port_do_register:3764: acquiring graph write lock
465 jack: 5402:245841411278 engine.c:jack_port_do_register:3852: release graph lock
466 jack: 5402:245841411280 engine.c:do_request:1350: status of request: 0
467 jack: 5402:245841411284 engine.c:do_request:1218: got a request of type 1
468 jack: 5402:245841411286 engine.c:jack_port_do_register:3764: acquiring graph write lock
469 jack: 5402:245841411291 engine.c:jack_port_do_register:3852: release graph lock
470 jack: 5402:245841411293 engine.c:do_request:1350: status of request: 0
471 jack: 5402:245841411298 engine.c:do_request:1218: got a request of type 1
472 jack: 5402:245841411300 engine.c:jack_port_do_register:3764: acquiring graph write lock
473 jack: 5402:245841411305 engine.c:jack_port_do_register:3852: release graph lock
474 jack: 5402:245841411307 engine.c:do_request:1350: status of request: 0
475 jack: 5402:245841411311 engine.c:do_request:1218: got a request of type 1
476 jack: 5402:245841411313 engine.c:jack_port_do_register:3764: acquiring graph write lock
477 jack: 5402:245841411319 engine.c:jack_port_do_register:3852: release graph lock
478 jack: 5402:245841411321 engine.c:do_request:1350: status of request: 0
479 jack: 5402:245841411325 engine.c:do_request:1218: got a request of type 1
480 jack: 5402:245841411327 engine.c:jack_port_do_register:3764: acquiring graph write lock
481 jack: 5402:245841411333 engine.c:jack_port_do_register:3852: release graph lock
482 jack: 5402:245841411335 engine.c:do_request:1350: status of request: 0
483 jack: 5402:245841411339 engine.c:do_request:1218: got a request of type 1
484 jack: 5402:245841411341 engine.c:jack_port_do_register:3764: acquiring graph write lock
485 jack: 5402:245841411347 engine.c:jack_port_do_register:3852: release graph lock
486 jack: 5402:245841411349 engine.c:do_request:1350: status of request: 0
487 jack: 5402:245841411353 engine.c:do_request:1218: got a request of type 1
488 jack: 5402:245841411355 engine.c:jack_port_do_register:3764: acquiring graph write lock
489 jack: 5402:245841411361 engine.c:jack_port_do_register:3852: release graph lock
490 jack: 5402:245841411363 engine.c:do_request:1350: status of request: 0
491 jack: 5402:245841411367 engine.c:do_request:1218: got a request of type 1
492 jack: 5402:245841411369 engine.c:jack_port_do_register:3764: acquiring graph write lock
493 jack: 5402:245841411375 engine.c:jack_port_do_register:3852: release graph lock
494 jack: 5402:245841411377 engine.c:do_request:1350: status of request: 0
495 jack: 5402:245841411382 engine.c:do_request:1218: got a request of type 1
496 jack: 5402:245841411384 engine.c:jack_port_do_register:3764: acquiring graph write lock
497 jack: 5402:245841411390 engine.c:jack_port_do_register:3852: release graph lock
498 jack: 5402:245841411392 engine.c:do_request:1350: status of request: 0
499 jack: 5402:245841411401 engine.c:do_request:1218: got a request of type 1
500 jack: 5402:245841411403 engine.c:jack_port_do_register:3764: acquiring graph write lock
501 jack: 5402:245841411409 engine.c:jack_port_do_register:3852: release graph lock
502 jack: 5402:245841411412 engine.c:do_request:1350: status of request: 0
503 jack: 5402:245841411416 engine.c:do_request:1218: got a request of type 1
504 jack: 5402:245841411418 engine.c:jack_port_do_register:3764: acquiring graph write lock
505 jack: 5402:245841411424 engine.c:jack_port_do_register:3852: release graph lock
506 jack: 5402:245841411426 engine.c:do_request:1350: status of request: 0
507 jack: 5402:245841411430 engine.c:do_request:1218: got a request of type 1
508 jack: 5402:245841411432 engine.c:jack_port_do_register:3764: acquiring graph write lock
509 jack: 5402:245841411438 engine.c:jack_port_do_register:3852: release graph lock
510 jack: 5402:245841411440 engine.c:do_request:1350: status of request: 0
511 jack: 5402:245841411444 engine.c:do_request:1218: got a request of type 1
512 jack: 5402:245841411446 engine.c:jack_port_do_register:3764: acquiring graph write lock
513 jack: 5402:245841411453 engine.c:jack_port_do_register:3852: release graph lock
514 jack: 5402:245841411455 engine.c:do_request:1350: status of request: 0
515 jack: 5402:245841411459 engine.c:do_request:1218: got a request of type 1
516 jack: 5402:245841411461 engine.c:jack_port_do_register:3764: acquiring graph write lock
517 jack: 5402:245841411467 engine.c:jack_port_do_register:3852: release graph lock
518 jack: 5402:245841411469 engine.c:do_request:1350: status of request: 0
519 jack: 5402:245841411474 engine.c:do_request:1218: got a request of type 1
520 jack: 5402:245841411476 engine.c:jack_port_do_register:3764: acquiring graph write lock
521 jack: 5402:245841411482 engine.c:jack_port_do_register:3852: release graph lock
522 jack: 5402:245841411484 engine.c:do_request:1350: status of request: 0
523 jack: 5402:245841411488 engine.c:do_request:1218: got a request of type 1
524 jack: 5402:245841411490 engine.c:jack_port_do_register:3764: acquiring graph write lock
525 jack: 5402:245841411497 engine.c:jack_port_do_register:3852: release graph lock
526 jack: 5402:245841411499 engine.c:do_request:1350: status of request: 0
527 jack: 5402:245841411503 engine.c:do_request:1218: got a request of type 1
528 245841411627: Debug (ffado.cpp)[ 189] ffado_streaming_prepare: Preparing...
529 jack: 5402:245841411505 engine.c:jack_port_do_register:3764: acquiring graph write lock
530 245841411636: Debug (StreamProcessorManager.cpp)[ 315] prepare: Preparing...
531 245841411644: Debug (StreamProcessorManager.cpp)[ 349] prepare: Prepare Receive processors...
532 245841412144: Debug (StreamProcessorManager.cpp)[ 355] prepare:  note: could not set slaveMode option for (0x1be50e0)...
533 245841412149: Debug (StreamProcessor.cpp)[1066] prepare: Prepare SP (0x1be50e0)...
534 jack: 5402:245841411512 engine.c:jack_port_do_register:3852: release graph lock
535 245841412152: Debug (StreamProcessor.cpp)[1070] prepare:  Allocate scratch buffer of 53248 quadlets
536 245841412157: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_cap_Mix-L
537 245841412160: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_cap_Mix-L
538 245841412164: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_cap_Mix-R
539 245841412167: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_cap_Mix-R
540 245841412170: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_cap_Analog1
541 245841412173: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_cap_Analog1
542 245841412176: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_cap_Analog2
543 245841412178: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_cap_Analog2
544 245841412181: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_cap_Analog3
545 245841412184: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_cap_Analog3
546 245841412187: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_cap_Analog4
547 jack: 5402:245841411514 engine.c:do_request:1350: status of request: 0
548 jack: 5402:245841411518 engine.c:do_request:1218: got a request of type 1
549 245841412190: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_cap_Analog4
550 245841412193: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_cap_Analog5
551 245841412195: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_cap_Analog5
552 245841412199: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_cap_Analog6
553 245841412201: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_cap_Analog6
554 245841412204: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_cap_Analog7
555 245841412207: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_cap_Analog7
556 245841412210: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_cap_Analog8
557 245841412213: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_cap_Analog8
558 245841412216: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_cap_unknown-1
559 245841412219: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_cap_unknown-1
560 245841412222: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_cap_unknown-2
561 245841412224: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_cap_unknown-2
562 245841412227: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_cap_AES/EBU1
563 245841412230: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_cap_AES/EBU1
564 245841412233: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_cap_AES/EBU2
565 245841412236: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_cap_AES/EBU2
566 245841412239: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_cap_MIDI0
567 245841412242: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_cap_MIDI0
568 245841412245: Debug (PortManager.cpp)[ 202] initPorts: init ports
569 245841412248: Debug (Port.cpp)[  61] init: Initialize port dev0_cap_Mix-L
570 245841412251: Debug (Port.cpp)[  61] init: Initialize port dev0_cap_Mix-R
571 245841412254: Debug (Port.cpp)[  61] init: Initialize port dev0_cap_Analog1
572 245841412257: Debug (Port.cpp)[  61] init: Initialize port dev0_cap_Analog2
573 245841412259: Debug (Port.cpp)[  61] init: Initialize port dev0_cap_Analog3
574 245841412262: Debug (Port.cpp)[  61] init: Initialize port dev0_cap_Analog4
575 245841412265: Debug (Port.cpp)[  61] init: Initialize port dev0_cap_Analog5
576 245841412267: Debug (Port.cpp)[  61] init: Initialize port dev0_cap_Analog6
577 245841412270: Debug (Port.cpp)[  61] init: Initialize port dev0_cap_Analog7
578 245841412273: Debug (Port.cpp)[  61] init: Initialize port dev0_cap_Analog8
579 245841412275: Debug (Port.cpp)[  61] init: Initialize port dev0_cap_unknown-1
580 245841412278: Debug (Port.cpp)[  61] init: Initialize port dev0_cap_unknown-2
581 245841412281: Debug (Port.cpp)[  61] init: Initialize port dev0_cap_AES/EBU1
582 245841412283: Debug (Port.cpp)[  61] init: Initialize port dev0_cap_AES/EBU2
583 245841412286: Debug (Port.cpp)[  61] init: Initialize port dev0_cap_MIDI0
584 245841412289: Debug (MotuReceiveStreamProcessor.cpp)[ 105] prepareChild: Preparing (0x1be50e0)...
585 245841412292: Debug (StreamProcessor.cpp)[1104] prepare: Prepared for:
586 245841412295: Debug (StreamProcessor.cpp)[1106] prepare:  Samplerate: 44100  [DLL Bandwidth: 0.100000 Hz]
587 245841412304: Debug (StreamProcessor.cpp)[1108] prepare:  PeriodSize: 1024, NbBuffers: 4
588 245841412307: Debug (StreamProcessor.cpp)[1110] prepare:  Port: 0, Channel: -1
589 245841412310: Debug (StreamProcessor.cpp)[1650] updateState: Do state transition: ePS_Created => ePS_Stopped
590 245841412314: Debug (StreamProcessor.cpp)[1357] doStop: Enter from state: ePS_Created
591 245841412318: Debug (StreamProcessor.cpp)[1368] doStop: Initializing remote ticks/frame to 557.278931
592 245841412326: Debug (TimestampedBuffer.cpp)[ 140] setNominalRate:  nominal rate 0.000000e+00 => 5.572789e+02
593 245841412332: Debug (TimestampedBuffer.cpp)[ 100] setBandwidth:  bandwidth 2.243042e-06 => 2.034505e-07
594 245841412337: Debug (TimestampedBuffer.cpp)[ 365] prepare: Preparing buffer (0x1be4f10)
595 245841412339: Debug (TimestampedBuffer.cpp)[ 367] prepare:  Size=4097 events, events/frame=1, event size=52bytes
596 245841412343: Debug (TimestampedBuffer.cpp)[ 370] prepare:  update period 8
597 245841412345: Debug (TimestampedBuffer.cpp)[ 372] prepare:  nominal rate=557.278931
598 245841412350: Debug (TimestampedBuffer.cpp)[ 374] prepare:  wrapping at 3145728000.000
599 245841412493: Debug (IsoHandlerManager.cpp)[ 134] updateShadowMapHelper: (0x1bcbb30) updating shadow vars...
600 245841412500: Debug (IsoHandlerManager.cpp)[ 174] updateShadowMapHelper: (0x1bcbb30) Receive handler 0x1be4da0 skipped (disabled)
601 245841412503: Debug (IsoHandlerManager.cpp)[ 190] updateShadowMapHelper: (0x1bcbb30) updated shadow vars...
602 245841413094: Debug (IsoHandlerManager.cpp)[ 134] updateShadowMapHelper: (0x1bcb910) updating shadow vars...
603 245841413100: Debug (IsoHandlerManager.cpp)[ 174] updateShadowMapHelper: (0x1bcb910) Transmit handler 0x1be5040 skipped (disabled)
604 245841413104: Debug (IsoHandlerManager.cpp)[ 190] updateShadowMapHelper: (0x1bcb910) updated shadow vars...
605 245841413285: Debug (StreamProcessor.cpp)[1386] doStop: DLL info: nominal tpf: 557.278931, update period: 8, bandwidth: 2.034505e-07 1/ticks (5.000000e+00 Hz)
606 245841413296: Debug (TimestampedBuffer.cpp)[ 343] clearBuffer: Clearing buffer
607 245841413299: Debug (PortManager.cpp)[ 219] preparePorts: preparing ports
608 245841413304: Debug (StreamProcessor.cpp)[1410] doStop: State switch complete, dumping SP info...
609  StreamProcessor 0x1be50e0, Receive:
610   Port, Channel    : 0, -1
611   Packets, Dropped, Skipped : 0, 0, 0
612   Now                   : 02507699803 (102s 0308c 1627t)
613   Xrun?                 : False
614   State                 : ePS_Stopped
615   Buffer                : 0x1be4f10
616   Framerate             : Nominal: 44100, Sync: 44099.998489, Buffer 44099.998489
617   TimestampedBuffer (0x1be4f10): 0000 frames, 0000 events
618    Timestamps           : head:          1.000, Tail: 3145728001.000, Next tail: 3145728001.000
619     Head - Tail         : -3145728000.000 (-5644799.806538 frames)
620    DLL Rate             : 4458.231445 (557.278931)
621    DLL Bandwidth        : 2.034505e-07 1/ticks (5.000000 Hz)
622 245841413349: Debug (StreamProcessorManager.cpp)[ 363] prepare: Prepare Transmit processors...
623 245841413354: Debug (StreamProcessorManager.cpp)[ 368] prepare:  note: could not set slaveMode option for (0x1be5a20)...
624 245841413358: Debug (StreamProcessor.cpp)[1066] prepare: Prepare SP (0x1be5a20)...
625 245841413361: Debug (StreamProcessor.cpp)[1070] prepare:  Allocate scratch buffer of 53248 quadlets
626 245841413365: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_pbk_Phones-L
627 245841413368: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_pbk_Phones-L
628 245841413371: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_pbk_Phones-R
629 245841413374: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_pbk_Phones-R
630 245841413377: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_pbk_Analog1
631 245841413380: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_pbk_Analog1
632 245841413383: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_pbk_Analog2
633 245841413386: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_pbk_Analog2
634 245841413389: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_pbk_Analog3
635 245841413391: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_pbk_Analog3
636 jack: 5402:245841411520 engine.c:jack_port_do_register:3764: acquiring graph write lock
637 245841413394: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_pbk_Analog4
638 jack: 5402:245841411527 engine.c:jack_port_do_register:3852: release graph lock
639 245841413397: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_pbk_Analog4
640 245841413400: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_pbk_Analog5
641 245841413403: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_pbk_Analog5
642 245841413406: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_pbk_Analog6
643 245841413408: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_pbk_Analog6
644 245841413412: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_pbk_Analog7
645 245841413414: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_pbk_Analog7
646 245841413417: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_pbk_Analog8
647 245841413420: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_pbk_Analog8
648 245841413423: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_pbk_MainOut-L
649 245841413426: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_pbk_MainOut-L
650 245841413429: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_pbk_MainOut-R
651 245841413432: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_pbk_MainOut-R
652 245841413435: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_pbk_AES/EBU1
653 245841413438: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_pbk_AES/EBU1
654 245841413441: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_pbk_AES/EBU2
655 245841413443: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_pbk_AES/EBU2
656 245841413446: Debug (StreamProcessor.cpp)[1085] prepare: Setting up port dev0_pbk_MIDI0
657 245841413449: Debug (Port.cpp)[  92] setBufferSize: Setting buffersize to 1024 for port dev0_pbk_MIDI0
658 245841413452: Debug (PortManager.cpp)[ 202] initPorts: init ports
659 245841413455: Debug (Port.cpp)[  61] init: Initialize port dev0_pbk_Phones-L
660 245841413458: Debug (Port.cpp)[  61] init: Initialize port dev0_pbk_Phones-R
661 245841413460: Debug (Port.cpp)[  61] init: Initialize port dev0_pbk_Analog1
662 245841413463: Debug (Port.cpp)[  61] init: Initialize port dev0_pbk_Analog2
663 245841413466: Debug (Port.cpp)[  61] init: Initialize port dev0_pbk_Analog3
664 245841413469: Debug (Port.cpp)[  61] init: Initialize port dev0_pbk_Analog4
665 245841413471: Debug (Port.cpp)[  61] init: Initialize port dev0_pbk_Analog5
666 jack: 5402:245841411529 engine.c:do_request:1350: status of request: 0
667 245841413474: Debug (Port.cpp)[  61] init: Initialize port dev0_pbk_Analog6
668 245841413476: Debug (Port.cpp)[  61] init: Initialize port dev0_pbk_Analog7
669 245841413479: Debug (Port.cpp)[  61] init: Initialize port dev0_pbk_Analog8
670 245841413482: Debug (Port.cpp)[  61] init: Initialize port dev0_pbk_MainOut-L
671 245841413484: Debug (Port.cpp)[  61] init: Initialize port dev0_pbk_MainOut-R
672 245841413487: Debug (Port.cpp)[  61] init: Initialize port dev0_pbk_AES/EBU1
673 245841413490: Debug (Port.cpp)[  61] init: Initialize port dev0_pbk_AES/EBU2
674 245841413492: Debug (Port.cpp)[  61] init: Initialize port dev0_pbk_MIDI0
675 245841413496: Debug (MotuTransmitStreamProcessor.cpp)[ 516] prepareChild: Preparing (0x1be5a20)...
676 245841413499: Debug (StreamProcessor.cpp)[1104] prepare: Prepared for:
677 245841413502: Debug (StreamProcessor.cpp)[1106] prepare:  Samplerate: 44100  [DLL Bandwidth: 0.100000 Hz]
678 245841413506: Debug (StreamProcessor.cpp)[1108] prepare:  PeriodSize: 1024, NbBuffers: 4
679 245841413509: Debug (StreamProcessor.cpp)[1110] prepare:  Port: 0, Channel: -1
680 245841413512: Debug (StreamProcessor.cpp)[1650] updateState: Do state transition: ePS_Created => ePS_Stopped
681 245841413515: Debug (StreamProcessor.cpp)[1357] doStop: Enter from state: ePS_Created
682 245841413518: Debug (StreamProcessor.cpp)[1368] doStop: Initializing remote ticks/frame to 557.278931
683 245841413523: Debug (TimestampedBuffer.cpp)[ 140] setNominalRate:  nominal rate 0.000000e+00 => 5.572789e+02
684 245841413528: Debug (TimestampedBuffer.cpp)[ 100] setBandwidth:  bandwidth 1.752376e-08 => 2.034505e-07
685 245841413533: Debug (TimestampedBuffer.cpp)[ 365] prepare: Preparing buffer (0x1be6b20)
686 245841413535: Debug (TimestampedBuffer.cpp)[ 367] prepare:  Size=4097 events, events/frame=1, event size=52bytes
687 245841413538: Debug (TimestampedBuffer.cpp)[ 370] prepare:  update period 1024
688 245841413541: Debug (TimestampedBuffer.cpp)[ 372] prepare:  nominal rate=557.278931
689 245841413545: Debug (TimestampedBuffer.cpp)[ 374] prepare:  wrapping at 3145728000.000
690 245841413763: Debug (StreamProcessor.cpp)[1386] doStop: DLL info: nominal tpf: 557.278931, update period: 1024, bandwidth: 2.034505e-07 1/ticks (5.000000e+00 Hz)
691 245841413771: Debug (TimestampedBuffer.cpp)[ 343] clearBuffer: Clearing buffer
692 245841413774: Debug (PortManager.cpp)[ 219] preparePorts: preparing ports
693 245841413778: Debug (StreamProcessor.cpp)[1410] doStop: State switch complete, dumping SP info...
694  StreamProcessor 0x1be5a20, Transmit:
695   Port, Channel    : 0, -1
696   Packets, Dropped, Skipped : 0, 0, 0
697   Now                   : 02507711403 (102s 0312c 0939t)
698   Xrun?                 : False
699   State                 : ePS_Stopped
700   Buffer                : 0x1be6b20
701   Framerate             : Nominal: 44100, Sync: 44099.998489, Buffer 44099.998489
702   TimestampedBuffer (0x1be6b20): 0000 frames, 0000 events
703    Timestamps           : head:          1.000, Tail: 3145728001.000, Next tail: 3145728001.000
704     Head - Tail         : -3145728000.000 (-5644799.806538 frames)
705    DLL Rate             : 570653.625000 (557.278931)
706    DLL Bandwidth        : 2.034505e-07 1/ticks (5.000000 Hz)
707 245841413817: Debug (StreamProcessorManager.cpp)[ 387] prepare: setting activity timeout to 46439
708 245841413820: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
709 245841422055: Debug (ffado.cpp)[ 209] ffado_streaming_start: ------------- Start -------------
710 245841422070: Debug (devicemanager.cpp)[ 873] startStreamingOnDevice: Starting stream 0 of device 0x1be0ce0
711 245841422519: Debug (IsoHandlerManager.cpp)[ 134] updateShadowMapHelper: (0x1bcbb30) updating shadow vars...
712 245841422528: Debug (IsoHandlerManager.cpp)[ 174] updateShadowMapHelper: (0x1bcbb30) Receive handler 0x1be4da0 skipped (disabled)
713 245841422532: Debug (IsoHandlerManager.cpp)[ 190] updateShadowMapHelper: (0x1bcbb30) updated shadow vars...
714 245841423115: Debug (IsoHandlerManager.cpp)[ 134] updateShadowMapHelper: (0x1bcb910) updating shadow vars...
715 245841423123: Debug (IsoHandlerManager.cpp)[ 174] updateShadowMapHelper: (0x1bcb910) Transmit handler 0x1be5040 skipped (disabled)
716 245841423126: Debug (IsoHandlerManager.cpp)[ 190] updateShadowMapHelper: (0x1bcb910) updated shadow vars...
717 245841427593: Debug (devicemanager.cpp)[ 873] startStreamingOnDevice: Starting stream 1 of device 0x1be0ce0
718 245841433093: Debug (StreamProcessorManager.cpp)[ 908] start: Starting Processors...
719 245841433101: Debug (StreamProcessorManager.cpp)[ 398] startDryRunning: Putting StreamProcessor streams into dry-running state...
720 245841433104: Debug (StreamProcessorManager.cpp)[ 399] startDryRunning:  Schedule start dry-running...
721 245841433113: Debug (StreamProcessor.cpp)[1156] scheduleStartDryRunning: for Transmit SP (0x1be5a20)
722 245841433117: Debug (StreamProcessor.cpp)[1163] scheduleStartDryRunning:   Now                   : 02508186429 (102s 0466c 2877t)
723 245841433121: Debug (StreamProcessor.cpp)[1168] scheduleStartDryRunning:   Start at              : 02508800681 (102s 0666c 2729t)
724 245841433146: Debug (IsoHandlerManager.cpp)[1027] startHandlerForStream:  starting handler 0x1be5040 for stream 0x1be5a20
725 245841433152: Debug (IsoHandlerManager.cpp)[  88] requestShadowMapUpdate: (0x1bcb910) enter
726 245841433156: Debug (IsoHandlerManager.cpp)[  93] requestShadowMapUpdate: (0x1bcb910) exit
727 245841433162: Debug (StreamProcessor.cpp)[1156] scheduleStartDryRunning: for Receive SP (0x1be50e0)
728 245841433166: Debug (StreamProcessor.cpp)[1163] scheduleStartDryRunning:   Now                   : 02508187633 (102s 0467c 1009t)
729 245841433170: Debug (StreamProcessor.cpp)[1168] scheduleStartDryRunning:   Start at              : 02508801935 (102s 0667c 0911t)
730 245841433173: Debug (IsoHandlerManager.cpp)[1027] startHandlerForStream:  starting handler 0x1be4da0 for stream 0x1be50e0
731 245841433177: Debug (IsoHandlerManager.cpp)[  88] requestShadowMapUpdate: (0x1bcbb30) enter
732 245841433179: Debug (IsoHandlerManager.cpp)[  93] requestShadowMapUpdate: (0x1bcbb30) exit
733 245841433183: Debug (StreamProcessorManager.cpp)[ 432] startDryRunning:  Waiting for all SP's to be dry-running...
734 245841442552: Debug (IsoHandlerManager.cpp)[ 134] updateShadowMapHelper: (0x1bcbb30) updating shadow vars...
735 245841442559: Debug (IsoHandlerManager.cpp)[1859] updateState: (0x1be4da0) handler needs state update from 0 => 1
736 245841442563: Debug (IsoHandlerManager.cpp)[1861] updateState: handler has to be enabled
737 245841442566: Debug (IsoHandlerManager.cpp)[1700] enable: start on cycle 0
738 jack: 5402:245841411533 engine.c:do_request:1218: got a request of type 1
739 245841442609: Debug (IsoHandlerManager.cpp)[1724] enable: Preparing iso handler (0x1be4da0, client=0x1be50e0)
740   Handler type................: Receive
741   Port, Channel...............:  0,  0
742   Buffer, MaxPacketSize, IRQ..:   64,  624,   32
743   Last cycle, dropped.........:   -1,    0,    0
744 245841442754: Debug (IsoHandlerManager.cpp)[ 171] updateShadowMapHelper: (0x1bcbb30) Receive handler 0x1be4da0 added
745 245841442759: Debug (IsoHandlerManager.cpp)[ 190] updateShadowMapHelper: (0x1bcbb30) updated shadow vars...
746 245841443148: Debug (IsoHandlerManager.cpp)[ 134] updateShadowMapHelper: (0x1bcb910) updating shadow vars...
747 245841443155: Debug (IsoHandlerManager.cpp)[1859] updateState: (0x1be5040) handler needs state update from 0 => 1
748 245841443158: Debug (IsoHandlerManager.cpp)[1861] updateState: handler has to be enabled
749 245841443161: Debug (IsoHandlerManager.cpp)[1700] enable: start on cycle 0
750 245841443188: Debug (IsoHandlerManager.cpp)[1724] enable: Preparing iso handler (0x1be5040, client=0x1be5a20)
751   Handler type................: Transmit
752   Port, Channel...............:  0,  1
753   Buffer, MaxPacketSize, IRQ..:  128,  624,   64
754   Speed ..................:  2
755   Min ISOXMT bufferfill : 7999
756   Last cycle, dropped.........:   -1,    0,    0
757 245841443340: Debug (IsoHandlerManager.cpp)[ 171] updateShadowMapHelper: (0x1bcb910) Transmit handler 0x1be5040 added
758 245841443345: Debug (IsoHandlerManager.cpp)[ 190] updateShadowMapHelper: (0x1bcb910) updated shadow vars...
759 245841443358: Debug (IsoHandlerManager.cpp)[1630] getPacket: Handler for Transmit SP 0x1be5040 is alive (cycle = 0)
760 245841443365: Debug (StreamProcessor.cpp)[ 783] getPacket: Should update state from ePS_Stopped to ePS_WaitingForStream
761 245841443369: Debug (StreamProcessor.cpp)[1650] updateState: Do state transition: ePS_Stopped => ePS_WaitingForStream
762 245841443373: Debug (StreamProcessor.cpp)[1430] doWaitForRunningStream: Enter from state: ePS_Stopped
763 245841443376: Debug (StreamProcessor.cpp)[1444] doWaitForRunningStream: State switch complete, dumping SP info...
764  StreamProcessor 0x1be5a20, Transmit:
765   Port, Channel    : 0, 1
766 jack: 5402:245841411535 engine.c:jack_port_do_register:3764: acquiring graph write lock
767   Packets, Dropped, Skipped : 1, 0, 0
768   Now                   : 02508438745 (102s 0549c 0217t)
769 jack: 5402:245841411542 engine.c:jack_port_do_register:3852: release graph lock
770   Xrun?                 : False
771   State                 : ePS_WaitingForStream
772   Buffer                : 0x1be6b20
773   Framerate             : Nominal: 44100, Sync: 44099.998489, Buffer 44099.998489
774   TimestampedBuffer (0x1be6b20): 0000 frames, 0000 events
775    Timestamps           : head:          1.000, Tail: 3145728001.000, Next tail: 3145728001.000
776     Head - Tail         : -3145728000.000 (-5644799.806538 frames)
777    DLL Rate             : 570653.625000 (557.278931)
778    DLL Bandwidth        : 2.034505e-07 1/ticks (5.000000 Hz)
779 jack: 5402:245841411544 engine.c:do_request:1350: status of request: 0
780 jack: 5402:245841411548 engine.c:do_request:1218: got a request of type 1
781 jack: 5402:245841411550 engine.c:jack_port_do_register:3764: acquiring graph write lock
782 jack: 5402:245841411557 engine.c:jack_port_do_register:3852: release graph lock
783 jack: 5402:245841411559 engine.c:do_request:1350: status of request: 0
784 jack: 5402:245841411564 engine.c:do_request:1218: got a request of type 1
785 jack: 5402:245841411566 engine.c:jack_port_do_register:3764: acquiring graph write lock
786 jack: 5402:245841411573 engine.c:jack_port_do_register:3852: release graph lock
787 jack: 5402:245841411575 engine.c:do_request:1350: status of request: 0
788 jack: 5402:245841411579 engine.c:do_request:1218: got a request of type 1
789 jack: 5402:245841411581 engine.c:jack_port_do_register:3764: acquiring graph write lock
790 jack: 5402:245841411589 engine.c:jack_port_do_register:3852: release graph lock
791 jack: 5402:245841411591 engine.c:do_request:1350: status of request: 0
792 jack: 5402:245841411595 engine.c:do_request:1218: got a request of type 1
793 jack: 5402:245841411597 engine.c:jack_port_do_register:3764: acquiring graph write lock
794 jack: 5402:245841411604 engine.c:jack_port_do_register:3852: release graph lock
795 jack: 5402:245841411607 engine.c:do_request:1350: status of request: 0
796 jack: 5402:245841411611 engine.c:do_request:1218: got a request of type 1
797 jack: 5402:245841411613 engine.c:jack_port_do_register:3764: acquiring graph write lock
798 jack: 5402:245841411620 engine.c:jack_port_do_register:3852: release graph lock
799 jack: 5402:245841411622 engine.c:do_request:1350: status of request: 0
800 jack: 5402:245841420102 engine.c:do_request:1218: got a request of type 6
801 jack: 5402:245841420115 clientengine.c:jack_client_activate:819: acquiring graph write lock
802 jack: 5402:245841420124 engine.c:jack_get_fifo_fd:3572: /dev/shm/jack-0/default/jack-ack-fifo-5402-1
803 jack: 5402:245841421198 engine.c:jack_get_fifo_fd:3616: opened engine->fifo[1] == 13 (/dev/shm/jack-0/default/jack-ack-fifo-5402-1)
804 jack: 5402:245841421223 engine.c:jack_deliver_event:2460: delivering event (type 5)
805 jack: 5402:245841421225 engine.c:jack_deliver_event:2473: client firewire_pcm is still alive
806 jack: 5402:245841421228 engine.c:jack_deliver_event:2637: event delivered
807 jack: 5402:245841421230 clientengine.c:jack_client_activate:846: release graph lock
808 jack: 5402:245841421233 engine.c:do_request:1350: status of request: 0
809 245842376601: Debug (MotuReceiveStreamProcessor.cpp)[ 163] processPacketHeader: Packet from MOTU: length = 424
810 245842376620: Debug (StreamProcessor.cpp)[ 477] putPacket: Should update state from ePS_Stopped to ePS_WaitingForStream
811 245842376626: Debug (StreamProcessor.cpp)[1650] updateState: Do state transition: ePS_Stopped => ePS_WaitingForStream
812 245842376630: Debug (StreamProcessor.cpp)[1430] doWaitForRunningStream: Enter from state: ePS_Stopped
813 245842376633: Debug (StreamProcessor.cpp)[1444] doWaitForRunningStream: State switch complete, dumping SP info...
814  StreamProcessor 0x1be50e0, Receive:
815   Port, Channel    : 0, 0
816   Packets, Dropped, Skipped : 1, 0, 0
817   Now                   : 02531370616 (103s 0013c 2680t)
818   Xrun?                 : False
819   State                 : ePS_WaitingForStream
820   Buffer                : 0x1be4f10
821   Framerate             : Nominal: 44100, Sync: 44099.998489, Buffer 44099.998489
822   TimestampedBuffer (0x1be4f10): 0000 frames, 0000 events
823    Timestamps           : head:          1.000, Tail: 3145728001.000, Next tail: 3145728001.000
824     Head - Tail         : -3145728000.000 (-5644799.806538 frames)
825    DLL Rate             : 4458.231445 (557.278931)
826    DLL Bandwidth        : 2.034505e-07 1/ticks (5.000000 Hz)
827 245842442742: Debug (StreamProcessor.cpp)[ 641] getPacket: Should update state to WaitingForStream to DryRunning
828 245842442760: Debug (StreamProcessor.cpp)[1650] updateState: Do state transition: ePS_WaitingForStream => ePS_DryRunning
829 245842442764: Debug (StreamProcessor.cpp)[1465] doDryRunning: Enter from state: ePS_WaitingForStream
830 245842442768: Debug (StreamProcessor.cpp)[1471] doDryRunning: StreamProcessor 0x1be5a20 started dry-running
831 245842442772: Debug (StreamProcessor.cpp)[1496] doDryRunning: State switch complete, dumping SP info...
832  StreamProcessor 0x1be5a20, Transmit:
833   Port, Channel    : 0, 1
834   Packets, Dropped, Skipped : 667, 0, 0
835   Now                   : 02532995783 (103s 0542c 2759t)
836   Xrun?                 : False
837   State                 : ePS_DryRunning
838   Buffer                : 0x1be6b20
839   Framerate             : Nominal: 44100, Sync: 44099.998489, Buffer 44099.998489
840   TimestampedBuffer (0x1be6b20): 0000 frames, 0000 events
841    Timestamps           : head:          1.000, Tail: 3145728001.000, Next tail: 3145728001.000
842     Head - Tail         : -3145728000.000 (-5644799.806538 frames)
843    DLL Rate             : 570653.625000 (557.278931)
844    DLL Bandwidth        : 2.034505e-07 1/ticks (5.000000 Hz)
845 245842459489: Debug (StreamProcessor.cpp)[ 459] putPacket: Should update state to DryRunning due to good packet
846 245842459502: Debug (StreamProcessor.cpp)[1650] updateState: Do state transition: ePS_WaitingForStream => ePS_DryRunning
847 245842459506: Debug (StreamProcessor.cpp)[1465] doDryRunning: Enter from state: ePS_WaitingForStream
848 245842459510: Debug (StreamProcessor.cpp)[1471] doDryRunning: StreamProcessor 0x1be50e0 started dry-running
849 245842459514: Debug (StreamProcessor.cpp)[1496] doDryRunning: State switch complete, dumping SP info...
850  StreamProcessor 0x1be50e0, Receive:
851   Port, Channel    : 0, 0
852   Packets, Dropped, Skipped : 668, 0, 0
853   Now                   : 02533407130 (103s 0676c 2458t)
854   Xrun?                 : False
855   State                 : ePS_DryRunning
856   Buffer                : 0x1be4f10
857   Framerate             : Nominal: 44100, Sync: 44099.998489, Buffer 44099.998489
858   TimestampedBuffer (0x1be4f10): 0000 frames, 0000 events
859    Timestamps           : head: 2533385378.000, Tail: 2533385378.000, Next tail: 2533389836.231
860     Head - Tail         :          0.000 (0.000000 frames)
861    DLL Rate             : 4458.231445 (557.278931)
862    DLL Bandwidth        : 2.034505e-07 1/ticks (5.000000 Hz)
863 245842459841: Debug (StreamProcessorManager.cpp)[ 469] startDryRunning:  StreamProcessor streams dry-running...
864 245842459920: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting streaming.spm.signal_delay_ticks
865 245842459944: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting streaming.spm.signal_delay_ticks
866 245842459953: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'streaming.spm.signal_delay_ticks' not found
867 245842459970: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting streaming.spm.xmit_prebuffer_frames
868 245842460048: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting streaming.spm.xmit_prebuffer_frames
869 245842460058: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'streaming.spm.xmit_prebuffer_frames' not found
870 245842460076: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting streaming.spm.sync_wait_time_msec
871 245842460096: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting streaming.spm.sync_wait_time_msec
872 245842460105: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'streaming.spm.sync_wait_time_msec' not found
873 245842460121: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting streaming.spm.cycles_for_startup
874 245842460162: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting streaming.spm.cycles_for_startup
875 245842460198: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'streaming.spm.cycles_for_startup' not found
876 245842460227: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting streaming.spm.prestart_cycles_for_xmit
877 245842460248: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting streaming.spm.prestart_cycles_for_xmit
878 245842460256: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'streaming.spm.prestart_cycles_for_xmit' not found
879 245842460272: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting streaming.spm.prestart_cycles_for_recv
880 245842460292: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting streaming.spm.prestart_cycles_for_recv
881 245842460300: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'streaming.spm.prestart_cycles_for_recv' not found
882 245842460304: Debug (StreamProcessorManager.cpp)[ 497] syncStartAll: Finding minimal sync delay...
883 245842460309: Debug (StreamProcessorManager.cpp)[ 517] syncStartAll:  max_of_min_delay = 98304, max_packet_size_frames = 8...
884 245842460313: Debug (StreamProcessorManager.cpp)[ 531] syncStartAll: Waiting for sync...
885 245842676425: Debug (StreamProcessorManager.cpp)[ 558] syncStartAll: Propagate sync info...
886 245842676441: Debug (StreamProcessorManager.cpp)[ 569] syncStartAll:  sync source frame rate: 44099.074219 fps (557.290588 tpf)
887 245842676455: Debug (StreamProcessorManager.cpp)[ 579] syncStartAll:  sync at TS=02539301565 (103s 2595c 1725t)...
888 245842676460: Debug (StreamProcessorManager.cpp)[ 593] syncStartAll:   add 1104 frames (00000615248 ticks)...
889 245842676464: Debug (StreamProcessorManager.cpp)[ 599] syncStartAll:   => first sample at TS=02539916813 (103s 2795c 2573t)...
890 245842676468: Debug (StreamProcessorManager.cpp)[ 612] syncStartAll:   => xmit starts at  TS=02539855373 (103s 2775c 2573t)...
891 245842676471: Debug (StreamProcessorManager.cpp)[ 617] syncStartAll:   => recv starts at  TS=02539916813 (103s 2795c 2573t)...
892 245842676475: Debug (StreamProcessorManager.cpp)[ 626] syncStartAll:  sync delay: 98304 = 98304 + 0 ticks (000s 0032c 0000t) [176 frames]...
893 245842676479: Debug (StreamProcessorManager.cpp)[ 637] syncStartAll: The number of prebuffer frames (100) is not a multiple of the common block size (8), increased to 104...
894 245842676486: Debug (StreamProcessor.cpp)[ 197] setExtraBufferFrames: Setting extra buffer to 104 frames
895 245842676490: Debug (StreamProcessorManager.cpp)[ 666] syncStartAll:  transmit buffer tail 2539916813 => head TS 2539916813, fc=0...
896 245842676495: Debug (StreamProcessor.cpp)[ 197] setExtraBufferFrames: Setting extra buffer to 1024 frames
897 245842676498: Debug (StreamProcessor.cpp)[1202] scheduleStartRunning: for Receive SP (0x1be50e0)
898 245842676503: Debug (StreamProcessor.cpp)[1209] scheduleStartRunning:   Now                   : 02538738878 (103s 2412c 1214t)
899 245842676506: Debug (StreamProcessor.cpp)[1214] scheduleStartRunning:   Start at              : 02539916813 (103s 2795c 2573t)
900 245842676512: Debug (StreamProcessor.cpp)[1202] scheduleStartRunning: for Transmit SP (0x1be5a20)
901 245842676515: Debug (StreamProcessor.cpp)[1209] scheduleStartRunning:   Now                   : 02538739222 (103s 2412c 1558t)
902 245842676519: Debug (StreamProcessor.cpp)[1214] scheduleStartRunning:   Start at              : 02539855373 (103s 2775c 2573t)
903 245842677763: Debug (StreamProcessor.cpp)[ 477] putPacket: Should update state from ePS_DryRunning to ePS_WaitingForStreamEnable
904 245842677775: Debug (StreamProcessor.cpp)[1650] updateState: Do state transition: ePS_DryRunning => ePS_WaitingForStreamEnable
905 245842677780: Debug (StreamProcessor.cpp)[1516] doWaitForStreamEnable: Enter from state: ePS_DryRunning
906 245842678153: Debug (StreamProcessor.cpp)[1555] doWaitForStreamEnable: State switch complete, dumping SP info...
907  StreamProcessor 0x1be50e0, Receive:
908   Port, Channel    : 0, 0
909   Packets, Dropped, Skipped : 2410, 0, 0
910   Now                   : 02538779866 (103s 2425c 2266t)
911   Xrun?                 : False
912   State                 : ePS_WaitingForStreamEnable
913   Buffer                : 0x1be4f10
914   Framerate             : Nominal: 44100, Sync: 44099.998489, Buffer 44099.998489
915   TimestampedBuffer (0x1be4f10): 0000 frames, 0000 events
916    Timestamps           : head: 2538730900.000, Tail: 2538730900.000, Next tail: 2538735358.325
917     Head - Tail         :          0.000 (0.000000 frames)
918    DLL Rate             : 4458.231445 (557.278931)
919    DLL Bandwidth        : 2.034505e-07 1/ticks (5.000000 Hz)
920 245842678764: Debug (StreamProcessor.cpp)[ 783] getPacket: Should update state from ePS_DryRunning to ePS_WaitingForStreamEnable
921 245842678773: Debug (StreamProcessor.cpp)[1650] updateState: Do state transition: ePS_DryRunning => ePS_WaitingForStreamEnable
922 245842678778: Debug (StreamProcessor.cpp)[1516] doWaitForStreamEnable: Enter from state: ePS_DryRunning
923 245842678785: Debug (StreamProcessor.cpp)[1540] doWaitForStreamEnable: Prefill transmit SP 0x1be5a20 with 4200 frames (xmit prebuffer = 104)
924 245842679653: Debug (StreamProcessor.cpp)[1555] doWaitForStreamEnable: State switch complete, dumping SP info...
925  StreamProcessor 0x1be5a20, Transmit:
926   Port, Channel    : 0, 1
927   Packets, Dropped, Skipped : 2529, 0, 0
928   Now                   : 02538816725 (103s 2437c 2261t)
929   Xrun?                 : False
930   State                 : ePS_WaitingForStreamEnable
931   Buffer                : 0x1be6b20
932   Framerate             : Nominal: 44100, Sync: 44099.887399, Buffer 44099.998489
933   TimestampedBuffer (0x1be6b20): 4200 frames, 4200 events
934    Timestamps           : head: 2539916813.000, Tail: 2542257384.500, Next tail: 2542828038.125
935     Head - Tail         :   -2340571.500 (-4199.999984 frames)
936    DLL Rate             : 570653.625000 (557.278931)
937    DLL Bandwidth        : 2.034505e-07 1/ticks (5.000000 Hz)
938 245842706778: Debug (StreamProcessor.cpp)[ 626] getPacket: Should update state to Running
939 245842706796: Debug (StreamProcessor.cpp)[1650] updateState: Do state transition: ePS_WaitingForStreamEnable => ePS_Running
940 245842706801: Debug (StreamProcessor.cpp)[1576] doRunning: Enter from state: ePS_WaitingForStreamEnable
941 245842706805: Debug (StreamProcessor.cpp)[1581] doRunning: StreamProcessor 0x1be5a20 started running
942 245842706810: Debug (TimestampedBuffer.cpp)[ 100] setBandwidth:  bandwidth 2.034505e-07 => 4.069010e-09
943 245842706819: Debug (StreamProcessor.cpp)[1597] doRunning: State switch complete, dumping SP info...
944  StreamProcessor 0x1be5a20, Transmit:
945   Port, Channel    : 0, 1
946   Packets, Dropped, Skipped : 2776, 0, 0
947   Now                   : 02539484152 (103s 2654c 3064t)
948   Xrun?                 : False
949   State                 : ePS_Running
950   Buffer                : 0x1be6b20
951   Framerate             : Nominal: 44100, Sync: 44099.385089, Buffer 44099.998489
952   TimestampedBuffer (0x1be6b20): 4200 frames, 4200 events
953    Timestamps           : head: 2539916813.000, Tail: 2542257384.500, Next tail: 2542828038.125
954     Head - Tail         :   -2340571.500 (-4199.999984 frames)
955    DLL Rate             : 570653.625000 (557.278931)
956    DLL Bandwidth        : 4.069010e-09 1/ticks (0.100000 Hz)
957 245842725160: Debug (StreamProcessor.cpp)[ 341] putPacket: Should update state to Running
958 245842725172: Debug (StreamProcessor.cpp)[1650] updateState: Do state transition: ePS_WaitingForStreamEnable => ePS_Running
959 245842725176: Debug (StreamProcessor.cpp)[1576] doRunning: Enter from state: ePS_WaitingForStreamEnable
960 245842725179: Debug (StreamProcessor.cpp)[1581] doRunning: StreamProcessor 0x1be50e0 started running
961 245842725183: Debug (TimestampedBuffer.cpp)[ 100] setBandwidth:  bandwidth 2.034505e-07 => 4.069010e-09
962 245842725190: Debug (StreamProcessor.cpp)[1597] doRunning: State switch complete, dumping SP info...
963  StreamProcessor 0x1be50e0, Receive:
964   Port, Channel    : 0, 0
965   Packets, Dropped, Skipped : 2796, 0, 0
966   Now                   : 02539935508 (103s 2801c 2836t)
967   Xrun?                 : False
968   State                 : ePS_Running
969   Buffer                : 0x1be4f10
970   Framerate             : Nominal: 44100, Sync: 44099.240194, Buffer 44099.240194
971   TimestampedBuffer (0x1be4f10): 0000 frames, 0000 events
972    Timestamps           : head: 2539916813.000, Tail: 2539916813.000, Next tail: 2539921271.308
973     Head - Tail         :          0.000 (0.000000 frames)
974    DLL Rate             : 4458.308105 (557.288513)
975    DLL Bandwidth        : 4.069010e-09 1/ticks (0.100000 Hz)
976 245842725333: Debug (StreamProcessorManager.cpp)[ 749] syncStartAll:   initial time of transfer 2540487476, rate 557.288513...
977 245842725374: Debug (StreamProcessorManager.cpp)[ 768] syncStartAll:   preset transmit tail TS 2542257424, rate 557.288513...
978 245842725388: Debug (StreamProcessorManager.cpp)[ 779] syncStartAll:    => transmit head TS 2540282393, fc=3544...
979 245842725393: Debug (StreamProcessorManager.cpp)[ 795] alignReceivedStreams: Aligning received streams...
980 245842725437: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting streaming.spm.align_tries
981 245842725459: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting streaming.spm.align_tries
982 245842725468: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'streaming.spm.align_tries' not found
983 245842725485: Debug (Configuration.cpp)[ 307] getSetting:   temporary has no setting streaming.spm.align_average_time_msec
984 245842725505: Debug (Configuration.cpp)[ 307] getSetting:   /usr/share/libffado/configuration has no setting streaming.spm.align_average_time_msec
985 245842725514: Debug (Configuration.cpp)[ 247] getValueForSetting: path 'streaming.spm.align_average_time_msec' not found
986 245842725518: Debug (StreamProcessorManager.cpp)[ 812] alignReceivedStreams:  averaging over 17 periods...
987 245843123494: Debug (StreamProcessorManager.cpp)[ 847] alignReceivedStreams:  Average offsets:
988 245843123511: Debug (StreamProcessorManager.cpp)[ 858] alignReceivedStreams:    avg offset between SyncSP 0x1be50e0 and SP 0x1be50e0 is 0 ticks, 0 frames...
989 245843123517: Debug (StreamProcessorManager.cpp)[ 788] syncStartAll:  StreamProcessor streams running...
990 245843123521: Debug (StreamProcessorManager.cpp)[ 935] start:  Started...
991
992 ffado_streaming_wait
993 ============================================
994 Xruns: 0
995 ============================================
996 ----------------------------------------------------
997 Dumping StreamProcessorManager information...
998 Period count:     17
999 Data type: float
1000  Receive processors...
1001  StreamProcessor 0x1be50e0, Receive:
1002   Port, Channel    : 0, 0
1003   Packets, Dropped, Skipped : 5981, 0, 0
1004   Now                   : 02549724967 (103s 5988c 1831t)
1005   Xrun?                 : False
1006   State                 : ePS_Running
1007   Buffer                : 0x1be4f10
1008   Framerate             : Nominal: 44100, Sync: 44099.211215, Buffer 44099.211215
1009   TimestampedBuffer (0x1be4f10): 0160 frames, 0160 events
1010    Timestamps           : head: 2549618094.949, Tail: 2549707261.167, Next tail: 2549711719.479
1011     Head - Tail         :     -89166.219 (-160.000092 frames)
1012    DLL Rate             : 4458.308377 (557.288547)
1013    DLL Bandwidth        : 4.069010e-09 1/ticks (0.100000 Hz)
1014  Transmit processors...
1015  StreamProcessor 0x1be5a20, Transmit:
1016   Port, Channel    : 0, 1
1017   Packets, Dropped, Skipped : 6112, 0, 0
1018   Now                   : 02549726122 (103s 5988c 2986t)
1019   Xrun?                 : False
1020   State                 : ePS_Running
1021   Buffer                : 0x1be6b20
1022   Framerate             : Nominal: 44100, Sync: 44099.211215, Buffer 44099.235364
1023   TimestampedBuffer (0x1be6b20): 3312 frames, 3312 events
1024    Timestamps           : head: 2550112963.292, Tail: 2551958703.042, Next tail: 2552529366.567
1025     Head - Tail         :   -1845739.750 (-3312.000309 frames)
1026    DLL Rate             : 570663.444342 (557.288520)
1027    DLL Bandwidth        : 4.069010e-09 1/ticks (0.100000 Hz)
1028 ----------------------------------------------------
1029 Port Information
1030  Playback
1031     0 (0x1be20d0): [0x1be5a20] [ on] [  Audio] dev0_pbk_Phones-L
1032     1 (0x1be6cc0): [0x1be5a20] [ on] [  Audio] dev0_pbk_Phones-R
1033     2 (0x1be6d50): [0x1be5a20] [ on] [  Audio] dev0_pbk_Analog1
1034     3 (0x1be6de0): [0x1be5a20] [ on] [  Audio] dev0_pbk_Analog2
1035     4 (0x1be6e70): [0x1be5a20] [ on] [  Audio] dev0_pbk_Analog3
1036     5 (0x1be6fa0): [0x1be5a20] [ on] [  Audio] dev0_pbk_Analog4
1037     6 (0x1be7030): [0x1be5a20] [ on] [  Audio] dev0_pbk_Analog5
1038     7 (0x1be70c0): [0x1be5a20] [ on] [  Audio] dev0_pbk_Analog6
1039     8 (0x1be7150): [0x1be5a20] [ on] [  Audio] dev0_pbk_Analog7
1040     9 (0x1be6f10): [0x1be5a20] [ on] [  Audio] dev0_pbk_Analog8
1041    10 (0x1be6ec0): [0x1be5a20] [ on] [  Audio] dev0_pbk_MainOut-L
1042    11 (0x1be72f0): [0x1be5a20] [ on] [  Audio] dev0_pbk_MainOut-R
1043    12 (0x1be7380): [0x1be5a20] [ on] [  Audio] dev0_pbk_AES/EBU1
1044    13 (0x1be7410): [0x1be5a20] [ on] [  Audio] dev0_pbk_AES/EBU2
1045    14 (0x1be7460): [0x1be5a20] [ on] [   MIDI] dev0_pbk_MIDI0
1046  Capture
1047     0 (0x1bcb5e0): [0x1be50e0] [ on] [  Audio]  dev0_cap_Mix-L
1048     1 (0x1bdfaa0): [0x1be50e0] [ on] [  Audio]  dev0_cap_Mix-R
1049     2 (0x1bdfaf0): [0x1be50e0] [ on] [  Audio]  dev0_cap_Analog1
1050     3 (0x1bdfb60): [0x1be50e0] [ on] [  Audio]  dev0_cap_Analog2
1051     4 (0x1bcb890): [0x1be50e0] [ on] [  Audio]  dev0_cap_Analog3
1052     5 (0x1be55a0): [0x1be50e0] [ on] [  Audio]  dev0_cap_Analog4
1053     6 (0x1be5630): [0x1be50e0] [ on] [  Audio]  dev0_cap_Analog5
1054     7 (0x1be56c0): [0x1be50e0] [ on] [  Audio]  dev0_cap_Analog6
1055     8 (0x1be5750): [0x1be50e0] [ on] [  Audio]  dev0_cap_Analog7
1056     9 (0x1be5510): [0x1be50e0] [ on] [  Audio]  dev0_cap_Analog8
1057    10 (0x1be54c0): [0x1be50e0] [ on] [  Audio]  dev0_cap_unknown-1
1058    11 (0x1be5860): [0x1be50e0] [ on] [  Audio]  dev0_cap_unknown-2
1059    12 (0x1be58f0): [0x1be50e0] [ on] [  Audio]  dev0_cap_AES/EBU1
1060    13 (0x1be5980): [0x1be50e0] [ on] [  Audio]  dev0_cap_AES/EBU2
1061    14 (0x1be59d0): [0x1be50e0] [ on] [   MIDI]  dev0_cap_MIDI0
1062 ----------------------------------------------------
1063
1064 jack: 5416:245843146482 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1065 jack: 5416:245843146502 engine.c:jack_run_one_cycle:2150: release problem lock
1066 jack: 5416:245843146504 engine.c:jack_run_one_cycle:2153: waiting for driver read
1067
1068 jack: 5416:245843146543 engine.c:jack_run_one_cycle:2159: run process
1069
1070 jack: 5416:245843146551 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1071 jack: 5416:245843146554 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1072 jack: 5416:245843146759 engine.c:jack_run_one_cycle:2211: release graph lock
1073 jack: 5416:245843146765 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1074 jack: 5416:245843169698 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1075 jack: 5416:245843169711 engine.c:jack_run_one_cycle:2150: release problem lock
1076 jack: 5416:245843169714 engine.c:jack_run_one_cycle:2153: waiting for driver read
1077
1078 245843169739: Debug (MotuReceiveStreamProcessor.cpp)[ 404] decodeMotuCtrlEvents: syncing device control status stream
1079 245843169752: Debug (MotuReceiveStreamProcessor.cpp)[ 417] decodeMotuCtrlEvents: initialising device control status
1080 jack: 5416:245843169767 engine.c:jack_run_one_cycle:2159: run process
1081
1082 jack: 5416:245843169770 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1083 jack: 5416:245843169773 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1084 jack: 5416:245843169973 engine.c:jack_run_one_cycle:2211: release graph lock
1085 jack: 5416:245843169979 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1086 jack: 5416:245843192921 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1087 jack: 5416:245843192935 engine.c:jack_run_one_cycle:2150: release problem lock
1088 jack: 5416:245843192937 engine.c:jack_run_one_cycle:2153: waiting for driver read
1089
1090 jack: 5416:245843192979 engine.c:jack_run_one_cycle:2159: run process
1091
1092 jack: 5416:245843192986 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1093 jack: 5416:245843192989 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1094 jack: 5416:245843193193 engine.c:jack_run_one_cycle:2211: release graph lock
1095 jack: 5416:245843193199 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1096 jack: 5416:245843216142 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1097 jack: 5416:245843216155 engine.c:jack_run_one_cycle:2150: release problem lock
1098 jack: 5416:245843216157 engine.c:jack_run_one_cycle:2153: waiting for driver read
1099
1100 jack: 5416:245843216193 engine.c:jack_run_one_cycle:2159: run process
1101
1102 jack: 5416:245843216196 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1103 jack: 5416:245843216198 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1104 jack: 5416:245843216396 engine.c:jack_run_one_cycle:2211: release graph lock
1105 jack: 5416:245843216399 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1106 245843239396: Debug (MotuReceiveStreamProcessor.cpp)[ 426] decodeMotuCtrlEvents: device control status valid: n_mixbuses=4, n_channels=20
1107 jack: 5416:245843239366 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1108 jack: 5416:245843239378 engine.c:jack_run_one_cycle:2150: release problem lock
1109 jack: 5416:245843239380 engine.c:jack_run_one_cycle:2153: waiting for driver read
1110
1111 jack: 5416:245843239449 engine.c:jack_run_one_cycle:2159: run process
1112
1113 jack: 5416:245843239454 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1114 jack: 5416:245843239456 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1115 jack: 5416:245843239654 engine.c:jack_run_one_cycle:2211: release graph lock
1116 jack: 5416:245843239657 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1117 jack: 5416:245843262591 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1118 jack: 5416:245843262602 engine.c:jack_run_one_cycle:2150: release problem lock
1119 jack: 5416:245843262604 engine.c:jack_run_one_cycle:2153: waiting for driver read
1120
1121 jack: 5416:245843262641 engine.c:jack_run_one_cycle:2159: run process
1122
1123 jack: 5416:245843262644 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1124 jack: 5416:245843262646 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1125 jack: 5416:245843262860 engine.c:jack_run_one_cycle:2211: release graph lock
1126 jack: 5416:245843262865 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1127 jack: 5416:245843285815 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1128 jack: 5416:245843285827 engine.c:jack_run_one_cycle:2150: release problem lock
1129 jack: 5416:245843285830 engine.c:jack_run_one_cycle:2153: waiting for driver read
1130
1131 jack: 5416:245843285867 engine.c:jack_run_one_cycle:2159: run process
1132
1133 jack: 5416:245843285874 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1134 jack: 5416:245843285877 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1135 jack: 5416:245843286082 engine.c:jack_run_one_cycle:2211: release graph lock
1136 jack: 5416:245843286089 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1137 jack: 5416:245843309037 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1138 jack: 5416:245843309049 engine.c:jack_run_one_cycle:2150: release problem lock
1139 jack: 5416:245843309089 engine.c:jack_run_one_cycle:2159: run process
1140
1141 jack: 5416:245843309095 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1142 jack: 5416:245843309098 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1143 jack: 5416:245843309295 engine.c:jack_run_one_cycle:2211: release graph lock
1144 jack: 5416:245843309301 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1145 jack: 5416:245843332261 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1146 jack: 5416:245843332275 engine.c:jack_run_one_cycle:2150: release problem lock
1147 jack: 5416:245843332277 engine.c:jack_run_one_cycle:2153: waiting for driver read
1148
1149 jack: 5416:245843332314 engine.c:jack_run_one_cycle:2159: run process
1150
1151 jack: 5416:245843332317 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1152 jack: 5416:245843332319 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1153 jack: 5416:245843332534 engine.c:jack_run_one_cycle:2211: release graph lock
1154 jack: 5416:245843332541 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1155 jack: 5416:245843355482 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1156 jack: 5416:245843355492 engine.c:jack_run_one_cycle:2150: release problem lock
1157 jack: 5416:245843355494 engine.c:jack_run_one_cycle:2153: waiting for driver read
1158
1159 jack: 5416:245843355528 engine.c:jack_run_one_cycle:2159: run process
1160
1161 jack: 5416:245843355535 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1162 jack: 5416:245843355538 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1163 jack: 5416:245843355734 engine.c:jack_run_one_cycle:2211: release graph lock
1164 jack: 5416:245843355736 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1165 jack: 5416:245843378708 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1166 jack: 5416:245843378719 engine.c:jack_run_one_cycle:2150: release problem lock
1167 jack: 5416:245843378721 engine.c:jack_run_one_cycle:2153: waiting for driver read
1168
1169 jack: 5416:245843378758 engine.c:jack_run_one_cycle:2159: run process
1170
1171 jack: 5416:245843378765 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1172 jack: 5416:245843378768 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1173 jack: 5416:245843379015 engine.c:jack_run_one_cycle:2211: release graph lock
1174 jack: 5416:245843379019 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1175 jack: 5416:245843401931 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1176 jack: 5416:245843401943 engine.c:jack_run_one_cycle:2150: release problem lock
1177 jack: 5416:245843401945 engine.c:jack_run_one_cycle:2153: waiting for driver read
1178
1179 jack: 5416:245843401982 engine.c:jack_run_one_cycle:2159: run process
1180
1181 jack: 5416:245843401989 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1182 jack: 5416:245843401992 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1183 jack: 5416:245843402198 engine.c:jack_run_one_cycle:2211: release graph lock
1184 jack: 5416:245843402204 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1185 jack: 5416:245843425154 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1186 jack: 5416:245843425167 engine.c:jack_run_one_cycle:2150: release problem lock
1187 jack: 5416:245843425170 engine.c:jack_run_one_cycle:2153: waiting for driver read
1188
1189 jack: 5416:245843425211 engine.c:jack_run_one_cycle:2159: run process
1190
1191 jack: 5416:245843425214 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1192 jack: 5416:245843425216 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1193 jack: 5416:245843425415 engine.c:jack_run_one_cycle:2211: release graph lock
1194 jack: 5416:245843425424 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1195 jack: 5416:245843448376 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1196 jack: 5416:245843448389 engine.c:jack_run_one_cycle:2150: release problem lock
1197 jack: 5416:245843448391 engine.c:jack_run_one_cycle:2153: waiting for driver read
1198
1199 jack: 5416:245843448428 engine.c:jack_run_one_cycle:2159: run process
1200
1201 jack: 5416:245843448430 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1202 jack: 5416:245843448433 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1203 jack: 5416:245843448628 engine.c:jack_run_one_cycle:2211: release graph lock
1204 jack: 5416:245843448631 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1205 jack: 5416:245843471600 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1206 jack: 5416:245843471609 engine.c:jack_run_one_cycle:2150: release problem lock
1207 jack: 5416:245843471612 engine.c:jack_run_one_cycle:2153: waiting for driver read
1208
1209 jack: 5416:245843471644 engine.c:jack_run_one_cycle:2159: run process
1210
1211 jack: 5416:245843471652 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1212 jack: 5416:245843471654 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1213 jack: 5416:245843471852 engine.c:jack_run_one_cycle:2211: release graph lock
1214 jack: 5416:245843471857 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1215 jack: 5416:245843494825 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1216 jack: 5416:245843494862 engine.c:jack_run_one_cycle:2150: release problem lock
1217 jack: 5416:245843494867 engine.c:jack_run_one_cycle:2153: waiting for driver read
1218
1219 jack: 5416:245843494905 engine.c:jack_run_one_cycle:2159: run process
1220
1221 jack: 5416:245843494908 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1222 jack: 5416:245843494911 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1223 jack: 5416:245843495132 engine.c:jack_run_one_cycle:2211: release graph lock
1224 jack: 5416:245843495136 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1225 jack: 5416:245843518048 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1226 jack: 5416:245843518060 engine.c:jack_run_one_cycle:2150: release problem lock
1227 jack: 5416:245843518099 engine.c:jack_run_one_cycle:2159: run process
1228
1229 jack: 5416:245843518105 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1230 jack: 5416:245843518108 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1231 jack: 5416:245843518304 engine.c:jack_run_one_cycle:2211: release graph lock
1232 jack: 5416:245843518310 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1233 jack: 5416:245843541274 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1234 jack: 5416:245843541286 engine.c:jack_run_one_cycle:2150: release problem lock
1235 jack: 5416:245843541327 engine.c:jack_run_one_cycle:2159: run process
1236
1237 jack: 5416:245843541334 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1238 jack: 5416:245843541336 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1239 jack: 5416:245843541533 engine.c:jack_run_one_cycle:2211: release graph lock
1240 jack: 5416:245843541538 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1241 jack: 5416:245843564496 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1242 jack: 5416:245843564508 engine.c:jack_run_one_cycle:2150: release problem lock
1243 jack: 5416:245843564510 engine.c:jack_run_one_cycle:2153: waiting for driver read
1244
1245 jack: 5416:245843564545 engine.c:jack_run_one_cycle:2159: run process
1246
1247 jack: 5416:245843564548 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1248 jack: 5416:245843564551 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1249 jack: 5416:245843564747 engine.c:jack_run_one_cycle:2211: release graph lock
1250 jack: 5416:245843564750 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1251 jack: 5416:245843587718 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1252 jack: 5416:245843587729 engine.c:jack_run_one_cycle:2150: release problem lock
1253 jack: 5416:245843587731 engine.c:jack_run_one_cycle:2153: waiting for driver read
1254
1255 jack: 5416:245843587765 engine.c:jack_run_one_cycle:2159: run process
1256
1257 jack: 5416:245843587772 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1258 jack: 5416:245843587774 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1259 jack: 5416:245843587970 engine.c:jack_run_one_cycle:2211: release graph lock
1260 jack: 5416:245843587996 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1261 jack: 5416:245843610946 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1262 jack: 5416:245843610957 engine.c:jack_run_one_cycle:2150: release problem lock
1263 jack: 5416:245843610959 engine.c:jack_run_one_cycle:2153: waiting for driver read
1264
1265 jack: 5416:245843610995 engine.c:jack_run_one_cycle:2159: run process
1266
1267 jack: 5416:245843610998 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1268 jack: 5416:245843611000 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1269 jack: 5416:245843611205 engine.c:jack_run_one_cycle:2211: release graph lock
1270 jack: 5416:245843611208 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1271 jack: 5416:245843634173 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1272 jack: 5416:245843634187 engine.c:jack_run_one_cycle:2150: release problem lock
1273 jack: 5416:245843634189 engine.c:jack_run_one_cycle:2153: waiting for driver read
1274
1275 jack: 5416:245843634231 engine.c:jack_run_one_cycle:2159: run process
1276
1277 jack: 5416:245843634234 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1278 jack: 5416:245843634236 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1279 jack: 5416:245843634436 engine.c:jack_run_one_cycle:2211: release graph lock
1280 jack: 5416:245843634439 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1281 jack: 5416:245843657394 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1282 jack: 5416:245843657406 engine.c:jack_run_one_cycle:2150: release problem lock
1283 jack: 5416:245843657409 engine.c:jack_run_one_cycle:2153: waiting for driver read
1284
1285 jack: 5416:245843657450 engine.c:jack_run_one_cycle:2159: run process
1286
1287 jack: 5416:245843657453 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1288 jack: 5416:245843657456 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1289 jack: 5416:245843657653 engine.c:jack_run_one_cycle:2211: release graph lock
1290 jack: 5416:245843657656 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1291 jack: 5416:245843680616 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1292 jack: 5416:245843680627 engine.c:jack_run_one_cycle:2150: release problem lock
1293 jack: 5416:245843680629 engine.c:jack_run_one_cycle:2153: waiting for driver read
1294
1295 jack: 5416:245843680666 engine.c:jack_run_one_cycle:2159: run process
1296
1297 jack: 5416:245843680669 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1298 jack: 5416:245843680672 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1299 jack: 5416:245843680869 engine.c:jack_run_one_cycle:2211: release graph lock
1300 jack: 5416:245843680872 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1301 jack: 5416:245843703839 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1302 jack: 5416:245843703851 engine.c:jack_run_one_cycle:2150: release problem lock
1303 jack: 5416:245843703853 engine.c:jack_run_one_cycle:2153: waiting for driver read
1304
1305 jack: 5416:245843703890 engine.c:jack_run_one_cycle:2159: run process
1306
1307 jack: 5416:245843703892 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1308 jack: 5416:245843703895 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1309 jack: 5416:245843704091 engine.c:jack_run_one_cycle:2211: release graph lock
1310 jack: 5416:245843704094 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1311 jack: 5416:245843727063 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1312 jack: 5416:245843727076 engine.c:jack_run_one_cycle:2150: release problem lock
1313 jack: 5416:245843727079 engine.c:jack_run_one_cycle:2153: waiting for driver read
1314
1315 jack: 5416:245843727117 engine.c:jack_run_one_cycle:2159: run process
1316
1317 jack: 5416:245843727120 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1318 jack: 5416:245843727123 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1319 jack: 5416:245843727327 engine.c:jack_run_one_cycle:2211: release graph lock
1320 jack: 5416:245843727330 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1321 jack: 5416:245843750286 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1322 jack: 5416:245843750299 engine.c:jack_run_one_cycle:2150: release problem lock
1323 jack: 5416:245843750301 engine.c:jack_run_one_cycle:2153: waiting for driver read
1324
1325 jack: 5416:245843750339 engine.c:jack_run_one_cycle:2159: run process
1326
1327 jack: 5416:245843750341 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1328 jack: 5416:245843750344 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1329 jack: 5416:245843750557 engine.c:jack_run_one_cycle:2211: release graph lock
1330 jack: 5416:245843750566 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1331 jack: 5416:245843773511 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1332 jack: 5416:245843773523 engine.c:jack_run_one_cycle:2150: release problem lock
1333 jack: 5416:245843773525 engine.c:jack_run_one_cycle:2153: waiting for driver read
1334
1335 jack: 5416:245843773562 engine.c:jack_run_one_cycle:2159: run process
1336
1337 jack: 5416:245843773565 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1338 jack: 5416:245843773567 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1339 jack: 5416:245843773764 engine.c:jack_run_one_cycle:2211: release graph lock
1340 jack: 5416:245843773767 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1341 jack: 5416:245843796731 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1342 jack: 5416:245843796741 engine.c:jack_run_one_cycle:2150: release problem lock
1343 jack: 5416:245843796743 engine.c:jack_run_one_cycle:2153: waiting for driver read
1344
1345 jack: 5416:245843796777 engine.c:jack_run_one_cycle:2159: run process
1346
1347 jack: 5416:245843796784 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1348 jack: 5416:245843796787 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1349 jack: 5416:245843796984 engine.c:jack_run_one_cycle:2211: release graph lock
1350 jack: 5416:245843796987 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1351 jack: 5416:245843819960 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1352 jack: 5416:245843819972 engine.c:jack_run_one_cycle:2150: release problem lock
1353 jack: 5416:245843819974 engine.c:jack_run_one_cycle:2153: waiting for driver read
1354
1355 jack: 5416:245843820010 engine.c:jack_run_one_cycle:2159: run process
1356
1357 jack: 5416:245843820013 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1358 jack: 5416:245843820015 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1359 jack: 5416:245843820217 engine.c:jack_run_one_cycle:2211: release graph lock
1360 jack: 5416:245843820220 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1361 jack: 5416:245843843181 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1362 jack: 5416:245843843195 engine.c:jack_run_one_cycle:2150: release problem lock
1363 jack: 5416:245843843197 engine.c:jack_run_one_cycle:2153: waiting for driver read
1364
1365 jack: 5416:245843843236 engine.c:jack_run_one_cycle:2159: run process
1366
1367 jack: 5416:245843843238 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1368 jack: 5416:245843843241 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1369 jack: 5416:245843843455 engine.c:jack_run_one_cycle:2211: release graph lock
1370 jack: 5416:245843843459 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1371 jack: 5416:245843866405 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1372 jack: 5416:245843866420 engine.c:jack_run_one_cycle:2150: release problem lock
1373 jack: 5416:245843866422 engine.c:jack_run_one_cycle:2153: waiting for driver read
1374
1375 jack: 5416:245843866463 engine.c:jack_run_one_cycle:2159: run process
1376
1377 jack: 5416:245843866470 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1378 jack: 5416:245843866473 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1379 jack: 5416:245843866673 engine.c:jack_run_one_cycle:2211: release graph lock
1380 jack: 5416:245843866678 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1381 jack: 5416:245843889631 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1382 jack: 5416:245843889644 engine.c:jack_run_one_cycle:2150: release problem lock
1383 jack: 5416:245843889646 engine.c:jack_run_one_cycle:2153: waiting for driver read
1384
1385 jack: 5416:245843889686 engine.c:jack_run_one_cycle:2159: run process
1386
1387 jack: 5416:245843889689 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1388 jack: 5416:245843889691 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1389 jack: 5416:245843889889 engine.c:jack_run_one_cycle:2211: release graph lock
1390 jack: 5416:245843889892 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1391 jack: 5416:245843912853 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1392 jack: 5416:245843912863 engine.c:jack_run_one_cycle:2150: release problem lock
1393 jack: 5416:245843912865 engine.c:jack_run_one_cycle:2153: waiting for driver read
1394
1395 jack: 5416:245843912900 engine.c:jack_run_one_cycle:2159: run process
1396
1397 jack: 5416:245843912907 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1398 jack: 5416:245843912909 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1399 jack: 5416:245843913117 engine.c:jack_run_one_cycle:2211: release graph lock
1400 jack: 5416:245843913124 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1401 ^Cjack main caught signal 2
1402 jack: 5416:245843936075 engine.c:jack_run_one_cycle:2128: trying to acquire read lock
1403 jack: 5416:245843936087 engine.c:jack_run_one_cycle:2150: release problem lock
1404 jack: 5416:245843936129 engine.c:jack_run_one_cycle:2159: run process
1405
1406 jack: 5416:245843936136 engine.c:jack_engine_process:843: considering client firewire_pcm for processing
1407 jack: 5416:245843936138 engine.c:jack_process_internal:580: invoking an internal client's callbacks
1408 jack: 5416:245843936339 engine.c:jack_run_one_cycle:2211: release graph lock
1409 jack: 5416:245843936345 engine.c:jack_run_one_cycle:2212: cycle finished, status = 0
1410 245843936419: Debug (ffado.cpp)[ 218] ffado_streaming_stop: ------------- Stop -------------
1411 245843936462: Debug (StreamProcessorManager.cpp)[ 940] stop: Stopping...
1412 245843936471: Debug (StreamProcessorManager.cpp)[ 942] stop:  scheduling stop for all SP's...
1413 245843936477: Debug (StreamProcessor.cpp)[1251] scheduleStopRunning: for Receive SP (0x1be50e0)
1414 245843936482: Debug (StreamProcessor.cpp)[1258] scheduleStopRunning:   Now                   : 02569700043 (104s 4490c 2763t)
1415 245843936485: Debug (StreamProcessor.cpp)[1263] scheduleStopRunning:   Stop at              : 02575843896 (104s 6490c 2616t)
1416 245843936491: Debug (StreamProcessor.cpp)[1251] scheduleStopRunning: for Transmit SP (0x1be5a20)
1417 245843936494: Debug (StreamProcessor.cpp)[1258] scheduleStopRunning:   Now                   : 02569700338 (104s 4490c 3058t)
1418 245843936497: Debug (StreamProcessor.cpp)[1263] scheduleStopRunning:   Stop at              : 02575844264 (104s 6490c 2984t)
1419 245843936571: Debug (StreamProcessor.cpp)[ 477] putPacket: Should update state from ePS_Running to ePS_WaitingForStreamDisable
1420 245843936581: Debug (StreamProcessor.cpp)[1650] updateState: Do state transition: ePS_Running => ePS_WaitingForStreamDisable
1421 245843936586: Debug (StreamProcessor.cpp)[1617] doWaitForStreamDisable: Enter from state: ePS_Running
1422 245843936589: Debug (StreamProcessor.cpp)[1629] doWaitForStreamDisable: State switch complete, dumping SP info...
1423  StreamProcessor 0x1be50e0, Receive:
1424   Port, Channel    : 0, 0
1425   Packets, Dropped, Skipped : 12480, 0, 0
1426   Now                   : 02569702943 (104s 4491c 2591t)
1427   Xrun?                 : False
1428   State                 : ePS_WaitingForStreamDisable
1429   Buffer                : 0x1be4f10
1430   Framerate             : Nominal: 44100, Sync: 44099.162917, Buffer 44099.162917
1431   TimestampedBuffer (0x1be4f10): 0136 frames, 0136 events
1432    Timestamps           : head: 2569591340.393, Tail: 2569667131.760, Next tail: 2569671590.076
1433     Head - Tail         :     -75791.367 (-136.000173 frames)
1434    DLL Rate             : 4458.310042 (557.288755)
1435    DLL Bandwidth        : 4.069010e-09 1/ticks (0.100000 Hz)
1436 245843938938: Debug (StreamProcessor.cpp)[ 667] getPacket: Should update state from ePS_Running to ePS_WaitingForStreamDisable
1437 245843938948: Debug (StreamProcessor.cpp)[1650] updateState: Do state transition: ePS_Running => ePS_WaitingForStreamDisable
1438 245843938951: Debug (StreamProcessor.cpp)[1617] doWaitForStreamDisable: Enter from state: ePS_Running
1439 245843938954: Debug (StreamProcessor.cpp)[1629] doWaitForStreamDisable: State switch complete, dumping SP info...
1440  StreamProcessor 0x1be5a20, Transmit:
1441   Port, Channel    : 0, 1
1442   Packets, Dropped, Skipped : 12609, 0, 0
1443   Now                   : 02569761008 (104s 4510c 2288t)
1444   Xrun?                 : False
1445   State                 : ePS_WaitingForStreamDisable
1446   Buffer                : 0x1be6b20
1447   Framerate             : Nominal: 44100, Sync: 44099.162917, Buffer 44099.196725
1448   TimestampedBuffer (0x1be6b20): 3344 frames, 3344 events
1449    Timestamps           : head: 2570068359.105, Tail: 2571931933.730, Next tail: 2572502597.704
1450     Head - Tail         :   -1863574.625 (-3344.002692 frames)
1451    DLL Rate             : 570663.540561 (557.288614)
1452    DLL Bandwidth        : 4.069010e-09 1/ticks (0.100000 Hz)
1453 245844171002: Debug (StreamProcessor.cpp)[ 595] getPacket: Should update state to DryRunning
1454 245844171021: Debug (StreamProcessor.cpp)[1650] updateState: Do state transition: ePS_WaitingForStreamDisable => ePS_DryRunning
1455 245844171026: Debug (StreamProcessor.cpp)[1465] doDryRunning: Enter from state: ePS_WaitingForStreamDisable
1456 245844171030: Debug (TimestampedBuffer.cpp)[ 343] clearBuffer: Clearing buffer
1457 245844171035: Debug (StreamProcessor.cpp)[1496] doDryRunning: State switch complete, dumping SP info...
1458  StreamProcessor 0x1be5a20, Transmit:
1459   Port, Channel    : 0, 1
1460   Packets, Dropped, Skipped : 14491, 0, 0
1461   Now                   : 02575463939 (104s 6367c 0515t)
1462   Xrun?                 : False
1463   State                 : ePS_DryRunning
1464   Buffer                : 0x1be6b20
1465   Framerate             : Nominal: 44100, Sync: 44099.162917, Buffer 44099.998489
1466   TimestampedBuffer (0x1be6b20): 0000 frames, 0000 events
1467    Timestamps           : head: 2571931933.730, Tail: 2571931933.730, Next tail: 2572502597.704
1468     Head - Tail         :          0.000 (0.000000 frames)
1469    DLL Rate             : 570653.625000 (557.278931)
1470    DLL Bandwidth        : 4.069010e-09 1/ticks (0.100000 Hz)
1471 245844186981: Debug (StreamProcessor.cpp)[ 321] putPacket: Should update state to DryRunning
1472 245844186996: Debug (StreamProcessor.cpp)[1650] updateState: Do state transition: ePS_WaitingForStreamDisable => ePS_DryRunning
1473 245844187008: Debug (StreamProcessor.cpp)[1465] doDryRunning: Enter from state: ePS_WaitingForStreamDisable
1474 245844187012: Debug (TimestampedBuffer.cpp)[ 343] clearBuffer: Clearing buffer
1475 245844187016: Debug (StreamProcessor.cpp)[1496] doDryRunning: State switch complete, dumping SP info...
1476  StreamProcessor 0x1be50e0, Receive:
1477   Port, Channel    : 0, 0
1478   Packets, Dropped, Skipped : 14491, 0, 0
1479   Now                   : 02575856609 (104s 6494c 3041t)
1480   Xrun?                 : False
1481   State                 : ePS_DryRunning
1482   Buffer                : 0x1be4f10
1483   Framerate             : Nominal: 44100, Sync: 44099.998489, Buffer 44099.998489
1484   TimestampedBuffer (0x1be4f10): 0000 frames, 0000 events
1485    Timestamps           : head: 2569671590.076, Tail: 2569671590.076, Next tail: 2569676048.392
1486     Head - Tail         :          0.000 (0.000000 frames)
1487    DLL Rate             : 4458.231445 (557.278931)
1488    DLL Bandwidth        : 4.069010e-09 1/ticks (0.100000 Hz)
1489 245844187072: Warning (StreamProcessor.cpp)[ 389] putPacket: Instantanous samplerate more than 1% off nominal. [Nom fs: 44100.000000, Instantanous fs:    31.817562, diff: 44068.182438 (    0.999279)]
1490 245844187083: Debug (StreamProcessor.cpp)[ 401] putPacket: cy 6491 rather large TSP difference TS=02569671626 => TS=02575850855 (6179229, nom 4458)
1491 245844187089: Warning (TimestampedBuffer.cpp)[1053] incrementFrameCounter: (0x1be4f10) difference rather large (+): diff=   6174806.608, max=      1536.000, 2575850855.000, 2569676048.392
1492 245844187101: Warning (TimestampedBuffer.cpp)[ 249] calculateRate: (0x1be4f10) rate ( 681.69592) more that 10% off nominal (rate= 557.27893, diff=      5453.567, update_period=8)
1493 245844187314: Debug (StreamProcessor.cpp)[1226] scheduleStopDryRunning: for Receive SP (0x1be50e0)
1494 245844187353: Debug (StreamProcessor.cpp)[1233] scheduleStopDryRunning:   Now                   : 02575864546 (104s 6497c 1762t)
1495 245844187364: Debug (StreamProcessor.cpp)[1238] scheduleStopDryRunning:   Stop at              : 02582007613 (105s 0497c 0829t)
1496 245844187370: Debug (StreamProcessor.cpp)[1226] scheduleStopDryRunning: for Transmit SP (0x1be5a20)
1497 245844187374: Debug (StreamProcessor.cpp)[1233] scheduleStopDryRunning:   Now                   : 02575865111 (104s 6497c 2327t)
1498 245844187378: Debug (StreamProcessor.cpp)[1238] scheduleStopDryRunning:   Stop at              : 02582009013 (105s 0497c 2229t)
1499 245844188720: Debug (StreamProcessor.cpp)[ 477] putPacket: Should update state from ePS_DryRunning to ePS_Stopped
1500 245844188730: Debug (StreamProcessor.cpp)[1650] updateState: Do state transition: ePS_DryRunning => ePS_Stopped
1501 245844188734: Debug (StreamProcessor.cpp)[1357] doStop: Enter from state: ePS_DryRunning
1502 245844188738: Debug (IsoHandlerManager.cpp)[1059] stopHandlerForStream:  stopping handler 0x1be4da0 for stream 0x1be50e0
1503 245844188743: Debug (IsoHandlerManager.cpp)[  88] requestShadowMapUpdate: (0x1bcbb30) enter
1504 245844188747: Debug (IsoHandlerManager.cpp)[  93] requestShadowMapUpdate: (0x1bcbb30) exit
1505 245844188749: Debug (IsoHandlerManager.cpp)[1071] stopHandlerForStream:  requested disable for handler 0x1be4da0
1506 245844188752: Debug (TimestampedBuffer.cpp)[ 343] clearBuffer: Clearing buffer
1507 245844188756: Debug (PortManager.cpp)[ 219] preparePorts: preparing ports
1508 245844188762: Debug (StreamProcessor.cpp)[1410] doStop: State switch complete, dumping SP info...
1509  StreamProcessor 0x1be50e0, Receive:
1510   Port, Channel    : 0, 0
1511   Packets, Dropped, Skipped : 14496, 0, 0
1512   Now                   : 02575899415 (104s 6508c 2839t)
1513   Xrun?                 : False
1514   State                 : ePS_Stopped
1515   Buffer                : 0x1be4f10
1516   Framerate             : Nominal: 44100, Sync: 44099.998489, Buffer 44099.998489
1517   TimestampedBuffer (0x1be4f10): 0000 frames, 0000 events
1518    Timestamps           : head: 2575859771.000, Tail: 2575859771.000, Next tail: 2575864229.231
1519     Head - Tail         :          0.000 (0.000000 frames)
1520    DLL Rate             : 4458.231445 (557.278931)
1521    DLL Bandwidth        : 4.069010e-09 1/ticks (0.100000 Hz)
1522 245844188826: Debug (IsoHandlerManager.cpp)[ 134] updateShadowMapHelper: (0x1bcbb30) updating shadow vars...
1523 245844188832: Debug (IsoHandlerManager.cpp)[1859] updateState: (0x1be4da0) handler needs state update from 1 => 0
1524 245844188836: Debug (IsoHandlerManager.cpp)[1864] updateState: handler has to be disabled
1525 245844188839: Debug (IsoHandlerManager.cpp)[1782] disable: (0x1be4da0, Receive) enter...
1526 245844188842: Debug (IsoHandlerManager.cpp)[1793] disable: (0x1be4da0, Receive) wake up handle...
1527 245844188848: Debug (IsoHandlerManager.cpp)[1805] disable: (0x1be4da0, Receive) stop...
1528 245844188919: Debug (IsoHandlerManager.cpp)[ 174] updateShadowMapHelper: (0x1bcbb30) Receive handler 0x1be4da0 skipped (disabled)
1529 245844188928: Debug (IsoHandlerManager.cpp)[ 190] updateShadowMapHelper: (0x1bcbb30) updated shadow vars...
1530 245844190965: Debug (StreamProcessor.cpp)[ 783] getPacket: Should update state from ePS_DryRunning to ePS_Stopped
1531 245844190974: Debug (StreamProcessor.cpp)[1650] updateState: Do state transition: ePS_DryRunning => ePS_Stopped
1532 245844190978: Debug (StreamProcessor.cpp)[1357] doStop: Enter from state: ePS_DryRunning
1533 245844190982: Debug (IsoHandlerManager.cpp)[1059] stopHandlerForStream:  stopping handler 0x1be5040 for stream 0x1be5a20
1534 245844190986: Debug (IsoHandlerManager.cpp)[  88] requestShadowMapUpdate: (0x1bcb910) enter
1535 245844190989: Debug (IsoHandlerManager.cpp)[  93] requestShadowMapUpdate: (0x1bcb910) exit
1536 245844190992: Debug (IsoHandlerManager.cpp)[1071] stopHandlerForStream:  requested disable for handler 0x1be5040
1537 245844190995: Debug (TimestampedBuffer.cpp)[ 343] clearBuffer: Clearing buffer
1538 245844190998: Debug (PortManager.cpp)[ 219] preparePorts: preparing ports
1539 245844191002: Debug (StreamProcessor.cpp)[1410] doStop: State switch complete, dumping SP info...
1540  StreamProcessor 0x1be5a20, Transmit:
1541   Port, Channel    : 0, 1
1542   Packets, Dropped, Skipped : 14625, 0, 0
1543   Now                   : 02575954482 (104s 6526c 2610t)
1544   Xrun?                 : False
1545   State                 : ePS_Stopped
1546   Buffer                : 0x1be6b20
1547   Framerate             : Nominal: 44100, Sync: 44099.993659, Buffer 44099.998489
1548   TimestampedBuffer (0x1be6b20): 0000 frames, 0000 events
1549    Timestamps           : head: 2571931933.730, Tail: 2571931933.730, Next tail: 2572502597.704
1550     Head - Tail         :          0.000 (0.000000 frames)
1551    DLL Rate             : 570653.625000 (557.278931)
1552    DLL Bandwidth        : 4.069010e-09 1/ticks (0.100000 Hz)
1553 245844191118: Debug (IsoHandlerManager.cpp)[ 134] updateShadowMapHelper: (0x1bcb910) updating shadow vars...
1554 245844191133: Debug (IsoHandlerManager.cpp)[1859] updateState: (0x1be5040) handler needs state update from 1 => 0
1555 245844191140: Debug (IsoHandlerManager.cpp)[1864] updateState: handler has to be disabled
1556 245844191143: Debug (IsoHandlerManager.cpp)[1782] disable: (0x1be5040, Transmit) enter...
1557 245844191146: Debug (IsoHandlerManager.cpp)[1793] disable: (0x1be5040, Transmit) wake up handle...
1558 245844191152: Debug (IsoHandlerManager.cpp)[1805] disable: (0x1be5040, Transmit) stop...
1559 245844191218: Debug (IsoHandlerManager.cpp)[ 174] updateShadowMapHelper: (0x1bcb910) Transmit handler 0x1be5040 skipped (disabled)
1560 245844191227: Debug (IsoHandlerManager.cpp)[ 190] updateShadowMapHelper: (0x1bcb910) updated shadow vars...
1561 245844191421: Debug (StreamProcessorManager.cpp)[1050] stop:  Stopped...
1562 245844191432: Debug (devicemanager.cpp)[ 968] stopStreamingOnDevice: Stopping stream 0 of device 0x1be0ce0
1563 245844196617: Debug (devicemanager.cpp)[ 968] stopStreamingOnDevice: Stopping stream 1 of device 0x1be0ce0
1564 245844203514: Debug (devicemanager.cpp)[ 854] finishStreaming: Unlocking device (0x1be0ce0)
1565 245844203528: Debug (Configuration.cpp)[ 138] save: Not saving temporary config file: temporary
1566 245844203533: Debug (Configuration.cpp)[ 135] save: Not saving readonly config file: /usr/share/libffado/configuration
1567 245844203547: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element 0001f20000015a02 from DeviceManager
1568 245844203559: Debug (StreamProcessorManager.cpp)[ 253] unregisterProcessor: Unregistering processor (0x1be50e0)
1569 245844203570: Debug (StreamProcessorManager.cpp)[ 264] unregisterProcessor: unregistering sync source
1570 245844203576: Debug (PortManager.cpp)[ 268] getUpdateHandlerForPtr:  found
1571 245844203579: Debug (PortManager.cpp)[ 244] remPortManagerUpdateHandler: Removing PortManagerUpdate handler (0x1be4d30)
1572 245844203583: Debug (PortManager.cpp)[ 251] remPortManagerUpdateHandler:  found
1573 245844203588: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
1574 245844203599: Debug (IsoHandlerManager.cpp)[ 897] unregisterStream: Unregistering Receive stream 0x1be50e0
1575 245844203604: Debug (IsoHandlerManager.cpp)[1439] unregisterStream: unregistering stream (0x1be50e0)
1576 245844203607: Debug (IsoHandlerManager.cpp)[ 910] unregisterStream:  unregistered stream (0x1be50e0) from handler (0x1be4da0)...
1577 245844203611: Debug (IsoHandlerManager.cpp)[ 936] pruneHandlers: enter...
1578 245844203615: Debug (IsoHandlerManager.cpp)[ 945] pruneHandlers:  handler (0x1be4da0) not in use
1579 245844203624: Debug (IsoHandlerManager.cpp)[ 678] unregisterHandler: enter...
1580 245844203629: Debug (IsoHandlerManager.cpp)[  88] requestShadowMapUpdate: (0x1bcb910) enter
1581 245844203632: Debug (IsoHandlerManager.cpp)[  93] requestShadowMapUpdate: (0x1bcb910) exit
1582 245844203635: Debug (IsoHandlerManager.cpp)[  88] requestShadowMapUpdate: (0x1bcbb30) enter
1583 245844203638: Debug (IsoHandlerManager.cpp)[  93] requestShadowMapUpdate: (0x1bcbb30) exit
1584 245844203641: Debug (IsoHandlerManager.cpp)[ 956] pruneHandlers:  deleting handler (0x1be4da0)
1585 245844203647: Debug (IsoHandlerManager.cpp)[ 924] unregisterStream:  deleted stream (0x1be5a20) from list...
1586 jack: 5402:245844203236 engine.c:do_request:1218: got a request of type 2
1587 jack: 5402:245844203250 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1588 jack: 5402:245844203261 engine.c:jack_port_do_unregister:3903: release graph lock
1589 jack: 5402:245844203263 engine.c:do_request:1350: status of request: 0
1590 jack: 5402:245844203266 engine.c:do_request:1218: got a request of type 2
1591 jack: 5402:245844203268 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1592 jack: 5402:245844203271 engine.c:jack_port_do_unregister:3903: release graph lock
1593 jack: 5402:245844203273 engine.c:do_request:1350: status of request: 0
1594 jack: 5402:245844203275 engine.c:do_request:1218: got a request of type 2
1595 jack: 5402:245844203277 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1596 jack: 5402:245844203280 engine.c:jack_port_do_unregister:3903: release graph lock
1597 jack: 5402:245844203282 engine.c:do_request:1350: status of request: 0
1598 jack: 5402:245844203284 engine.c:do_request:1218: got a request of type 2
1599 jack: 5402:245844203286 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1600 jack: 5402:245844203289 engine.c:jack_port_do_unregister:3903: release graph lock
1601 jack: 5402:245844203290 engine.c:do_request:1350: status of request: 0
1602 jack: 5402:245844203292 engine.c:do_request:1218: got a request of type 2
1603 jack: 5402:245844203294 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1604 jack: 5402:245844203297 engine.c:jack_port_do_unregister:3903: release graph lock
1605 jack: 5402:245844203299 engine.c:do_request:1350: status of request: 0
1606 jack: 5402:245844203301 engine.c:do_request:1218: got a request of type 2
1607 jack: 5402:245844203303 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1608 jack: 5402:245844203306 engine.c:jack_port_do_unregister:3903: release graph lock
1609 jack: 5402:245844203308 engine.c:do_request:1350: status of request: 0
1610 jack: 5402:245844203310 engine.c:do_request:1218: got a request of type 2
1611 jack: 5402:245844203312 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1612 jack: 5402:245844203315 engine.c:jack_port_do_unregister:3903: release graph lock
1613 jack: 5402:245844203317 engine.c:do_request:1350: status of request: 0
1614 jack: 5402:245844203318 engine.c:do_request:1218: got a request of type 2
1615 jack: 5402:245844203320 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1616 jack: 5402:245844203323 engine.c:jack_port_do_unregister:3903: release graph lock
1617 jack: 5402:245844203325 engine.c:do_request:1350: status of request: 0
1618 jack: 5402:245844203327 engine.c:do_request:1218: got a request of type 2
1619 jack: 5402:245844203329 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1620 jack: 5402:245844203331 engine.c:jack_port_do_unregister:3903: release graph lock
1621 jack: 5402:245844203333 engine.c:do_request:1350: status of request: 0
1622 jack: 5402:245844203335 engine.c:do_request:1218: got a request of type 2
1623 jack: 5402:245844203337 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1624 jack: 5402:245844203340 engine.c:jack_port_do_unregister:3903: release graph lock
1625 jack: 5402:245844203342 engine.c:do_request:1350: status of request: 0
1626 jack: 5402:245844203344 engine.c:do_request:1218: got a request of type 2
1627 jack: 5402:245844203346 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1628 jack: 5402:245844203348 engine.c:jack_port_do_unregister:3903: release graph lock
1629 jack: 5402:245844203350 engine.c:do_request:1350: status of request: 0
1630 jack: 5402:245844203352 engine.c:do_request:1218: got a request of type 2
1631 jack: 5402:245844203354 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1632 jack: 5402:245844203357 engine.c:jack_port_do_unregister:3903: release graph lock
1633 jack: 5402:245844203359 engine.c:do_request:1350: status of request: 0
1634 jack: 5402:245844203361 engine.c:do_request:1218: got a request of type 2
1635 jack: 5402:245844203362 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1636 jack: 5402:245844203365 engine.c:jack_port_do_unregister:3903: release graph lock
1637 jack: 5402:245844203367 engine.c:do_request:1350: status of request: 0
1638 jack: 5402:245844203369 engine.c:do_request:1218: got a request of type 2
1639 jack: 5402:245844203371 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1640 jack: 5402:245844203373 engine.c:jack_port_do_unregister:3903: release graph lock
1641 jack: 5402:245844203375 engine.c:do_request:1350: status of request: 0
1642 jack: 5402:245844203377 engine.c:do_request:1218: got a request of type 2
1643 jack: 5402:245844203379 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1644 jack: 5402:245844203382 engine.c:jack_port_do_unregister:3903: release graph lock
1645 jack: 5402:245844203384 engine.c:do_request:1350: status of request: 0
1646 jack: 5402:245844203388 engine.c:do_request:1218: got a request of type 2
1647 jack: 5402:245844203390 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1648 jack: 5402:245844203392 engine.c:jack_port_do_unregister:3903: release graph lock
1649 jack: 5402:245844203394 engine.c:do_request:1350: status of request: 0
1650 jack: 5402:245844203396 engine.c:do_request:1218: got a request of type 2
1651 jack: 5402:245844203398 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1652 jack: 5402:245844203400 engine.c:jack_port_do_unregister:3903: release graph lock
1653 jack: 5402:245844203402 engine.c:do_request:1350: status of request: 0
1654 jack: 5402:245844203404 engine.c:do_request:1218: got a request of type 2
1655 jack: 5402:245844203406 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1656 245844204144: Debug (Port.cpp)[  49] ~Port: deleting port dev0_cap_Mix-L
1657 245844204151: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_cap_Mix-L
1658 245844204159: Debug (Port.cpp)[  49] ~Port: deleting port dev0_cap_Mix-R
1659 245844204162: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_cap_Mix-R
1660 245844204166: Debug (Port.cpp)[  49] ~Port: deleting port dev0_cap_Analog1
1661 245844204169: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_cap_Analog1
1662 245844204173: Debug (Port.cpp)[  49] ~Port: deleting port dev0_cap_Analog2
1663 245844204175: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_cap_Analog2
1664 245844204179: Debug (Port.cpp)[  49] ~Port: deleting port dev0_cap_Analog3
1665 245844204182: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_cap_Analog3
1666 245844204186: Debug (Port.cpp)[  49] ~Port: deleting port dev0_cap_Analog4
1667 245844204189: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_cap_Analog4
1668 245844204193: Debug (Port.cpp)[  49] ~Port: deleting port dev0_cap_Analog5
1669 245844204195: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_cap_Analog5
1670 245844204199: Debug (Port.cpp)[  49] ~Port: deleting port dev0_cap_Analog6
1671 245844204202: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_cap_Analog6
1672 245844204206: Debug (Port.cpp)[  49] ~Port: deleting port dev0_cap_Analog7
1673 245844204209: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_cap_Analog7
1674 245844204212: Debug (Port.cpp)[  49] ~Port: deleting port dev0_cap_Analog8
1675 245844204215: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_cap_Analog8
1676 245844204219: Debug (Port.cpp)[  49] ~Port: deleting port dev0_cap_unknown-1
1677 245844204222: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_cap_unknown-1
1678 245844204226: Debug (Port.cpp)[  49] ~Port: deleting port dev0_cap_unknown-2
1679 245844204229: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_cap_unknown-2
1680 245844204232: Debug (Port.cpp)[  49] ~Port: deleting port dev0_cap_AES/EBU1
1681 245844204235: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_cap_AES/EBU1
1682 245844204239: Debug (Port.cpp)[  49] ~Port: deleting port dev0_cap_AES/EBU2
1683 245844204242: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_cap_AES/EBU2
1684 245844204247: Debug (Port.cpp)[  49] ~Port: deleting port dev0_cap_MIDI0
1685 245844204250: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_cap_MIDI0
1686 245844204258: Debug (StreamProcessorManager.cpp)[ 253] unregisterProcessor: Unregistering processor (0x1be5a20)
1687 245844204262: Debug (PortManager.cpp)[ 268] getUpdateHandlerForPtr:  found
1688 245844204265: Debug (PortManager.cpp)[ 244] remPortManagerUpdateHandler: Removing PortManagerUpdate handler (0x1be2120)
1689 245844204268: Debug (PortManager.cpp)[ 251] remPortManagerUpdateHandler:  found
1690 245844204272: Debug (StreamProcessorManager.cpp)[1613] updateShadowLists: Updating port shadow lists...
1691 245844204275: Debug (IsoHandlerManager.cpp)[ 897] unregisterStream: Unregistering Transmit stream 0x1be5a20
1692 245844204279: Debug (IsoHandlerManager.cpp)[1439] unregisterStream: unregistering stream (0x1be5a20)
1693 245844204282: Debug (IsoHandlerManager.cpp)[ 910] unregisterStream:  unregistered stream (0x1be5a20) from handler (0x1be5040)...
1694 jack: 5402:245844203409 engine.c:jack_port_do_unregister:3903: release graph lock
1695 245844204285: Debug (IsoHandlerManager.cpp)[ 936] pruneHandlers: enter...
1696 245844204288: Debug (IsoHandlerManager.cpp)[ 945] pruneHandlers:  handler (0x1be5040) not in use
1697 245844204293: Debug (IsoHandlerManager.cpp)[ 678] unregisterHandler: enter...
1698 245844204296: Debug (IsoHandlerManager.cpp)[  88] requestShadowMapUpdate: (0x1bcb910) enter
1699 245844204299: Debug (IsoHandlerManager.cpp)[  93] requestShadowMapUpdate: (0x1bcb910) exit
1700 245844204302: Debug (IsoHandlerManager.cpp)[  88] requestShadowMapUpdate: (0x1bcbb30) enter
1701 245844204305: Debug (IsoHandlerManager.cpp)[  93] requestShadowMapUpdate: (0x1bcbb30) exit
1702 245844204307: Debug (IsoHandlerManager.cpp)[ 956] pruneHandlers:  deleting handler (0x1be5040)
1703 245844204311: Debug (IsoHandlerManager.cpp)[ 924] unregisterStream:  deleted stream (0x1be5a20) from list...
1704 jack: 5402:245844203411 engine.c:do_request:1350: status of request: 0
1705 jack: 5402:245844203413 engine.c:do_request:1218: got a request of type 2
1706 jack: 5402:245844203414 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1707 jack: 5402:245844203417 engine.c:jack_port_do_unregister:3903: release graph lock
1708 jack: 5402:245844203419 engine.c:do_request:1350: status of request: 0
1709 jack: 5402:245844203421 engine.c:do_request:1218: got a request of type 2
1710 jack: 5402:245844203423 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1711 jack: 5402:245844203425 engine.c:jack_port_do_unregister:3903: release graph lock
1712 jack: 5402:245844203427 engine.c:do_request:1350: status of request: 0
1713 jack: 5402:245844203429 engine.c:do_request:1218: got a request of type 2
1714 jack: 5402:245844203431 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1715 jack: 5402:245844203433 engine.c:jack_port_do_unregister:3903: release graph lock
1716 jack: 5402:245844203435 engine.c:do_request:1350: status of request: 0
1717 jack: 5402:245844203437 engine.c:do_request:1218: got a request of type 2
1718 jack: 5402:245844203439 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1719 jack: 5402:245844203441 engine.c:jack_port_do_unregister:3903: release graph lock
1720 jack: 5402:245844203443 engine.c:do_request:1350: status of request: 0
1721 jack: 5402:245844203446 engine.c:do_request:1218: got a request of type 2
1722 jack: 5402:245844203448 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1723 jack: 5402:245844203450 engine.c:jack_port_do_unregister:3903: release graph lock
1724 jack: 5402:245844203452 engine.c:do_request:1350: status of request: 0
1725 jack: 5402:245844203454 engine.c:do_request:1218: got a request of type 2
1726 jack: 5402:245844203456 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1727 jack: 5402:245844203458 engine.c:jack_port_do_unregister:3903: release graph lock
1728 jack: 5402:245844203460 engine.c:do_request:1350: status of request: 0
1729 jack: 5402:245844203462 engine.c:do_request:1218: got a request of type 2
1730 jack: 5402:245844203464 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1731 jack: 5402:245844203466 engine.c:jack_port_do_unregister:3903: release graph lock
1732 jack: 5402:245844203468 engine.c:do_request:1350: status of request: 0
1733 jack: 5402:245844203470 engine.c:do_request:1218: got a request of type 2
1734 jack: 5402:245844203472 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1735 245844204569: Debug (Port.cpp)[  49] ~Port: deleting port dev0_pbk_Phones-L
1736 jack: 5402:245844203474 engine.c:jack_port_do_unregister:3903: release graph lock
1737 245844204577: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_pbk_Phones-L
1738 245844204582: Debug (Port.cpp)[  49] ~Port: deleting port dev0_pbk_Phones-R
1739 245844204585: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_pbk_Phones-R
1740 245844204598: Debug (Port.cpp)[  49] ~Port: deleting port dev0_pbk_Analog1
1741 245844204601: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_pbk_Analog1
1742 245844204604: Debug (Port.cpp)[  49] ~Port: deleting port dev0_pbk_Analog2
1743 245844204607: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_pbk_Analog2
1744 245844204611: Debug (Port.cpp)[  49] ~Port: deleting port dev0_pbk_Analog3
1745 245844204614: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_pbk_Analog3
1746 245844204617: Debug (Port.cpp)[  49] ~Port: deleting port dev0_pbk_Analog4
1747 245844204620: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_pbk_Analog4
1748 245844204624: Debug (Port.cpp)[  49] ~Port: deleting port dev0_pbk_Analog5
1749 245844204626: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_pbk_Analog5
1750 245844204630: Debug (Port.cpp)[  49] ~Port: deleting port dev0_pbk_Analog6
1751 245844204633: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_pbk_Analog6
1752 245844204637: Debug (Port.cpp)[  49] ~Port: deleting port dev0_pbk_Analog7
1753 245844204639: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_pbk_Analog7
1754 245844204643: Debug (Port.cpp)[  49] ~Port: deleting port dev0_pbk_Analog8
1755 245844204647: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_pbk_Analog8
1756 245844204650: Debug (Port.cpp)[  49] ~Port: deleting port dev0_pbk_MainOut-L
1757 245844204653: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_pbk_MainOut-L
1758 245844204657: Debug (Port.cpp)[  49] ~Port: deleting port dev0_pbk_MainOut-R
1759 245844204660: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_pbk_MainOut-R
1760 245844204664: Debug (Port.cpp)[  49] ~Port: deleting port dev0_pbk_AES/EBU1
1761 245844204667: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_pbk_AES/EBU1
1762 245844204671: Debug (Port.cpp)[  49] ~Port: deleting port dev0_pbk_AES/EBU2
1763 245844204674: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_pbk_AES/EBU2
1764 245844204679: Debug (Port.cpp)[  49] ~Port: deleting port dev0_pbk_MIDI0
1765 245844204682: Debug (PortManager.cpp)[ 117] unregisterPort: unregistering port dev0_pbk_MIDI0
1766 245844204688: Debug (ieee1394service.cpp)[1445] freeIsoChannel: Freeing ISO channel 0...
1767 245844204692: Debug (ieee1394service.cpp)[1463] freeIsoChannel:  allocated using generic routine...
1768 245844204695: Debug (ieee1394service.cpp)[1464] freeIsoChannel:  freeing 441 bandwidth units...
1769 245844204737: Debug (ieee1394service.cpp)[1468] freeIsoChannel:  freeing channel 0...
1770 245844204768: Debug (ieee1394service.cpp)[1445] freeIsoChannel: Freeing ISO channel 1...
1771 245844204772: Debug (ieee1394service.cpp)[1463] freeIsoChannel:  allocated using generic routine...
1772 245844204775: Debug (ieee1394service.cpp)[1464] freeIsoChannel:  freeing 441 bandwidth units...
1773 245844204805: Debug (ieee1394service.cpp)[1468] freeIsoChannel:  freeing channel 1...
1774 245844204835: Debug (motu_mixer.cpp)[ 357] destroyMixer: destroy mixer...
1775 245844204843: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Mixer from 0001f20000015a02
1776 245844204851: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element fader from Mixer
1777 245844204866: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element pan from Mixer
1778 245844204875: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element solo from Mixer
1779 245844204884: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element mute from Mixer
1780 245844204892: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Mix1/Mix_fader from Mixer
1781 245844204897: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Mix1/Mix_mute from Mixer
1782 245844204901: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Mix1/Mix_dest from Mixer
1783 245844204905: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Mix2/Mix_fader from Mixer
1784 245844204909: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Mix2/Mix_mute from Mixer
1785 245844204913: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Mix2/Mix_dest from Mixer
1786 245844204917: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Mix3/Mix_fader from Mixer
1787 245844204921: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Mix3/Mix_mute from Mixer
1788 245844204925: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Mix3/Mix_dest from Mixer
1789 245844204929: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Mix4/Mix_fader from Mixer
1790 245844204934: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Mix4/Mix_mute from Mixer
1791 245844204937: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Mix4/Mix_dest from Mixer
1792 245844204941: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Mainout_fader from Mixer
1793 245844204945: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Phones_fader from Mixer
1794 245844204949: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Control/Phones_src from Mixer
1795 245844204953: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Control/OpticalIn_mode from Mixer
1796 245844204958: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Control/OpticalOut_mode from Mixer
1797 245844204962: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Control/Meter_peakhold_time from Mixer
1798 245844204967: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Control/Meter_cliphold_time from Mixer
1799 245844204971: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Control/Meter_aesebu_src from Mixer
1800 245844204975: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Control/Meter_src from Mixer
1801 245844204979: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Info/Model from Mixer
1802 245844204983: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Info/IsStreaming from Mixer
1803 245844204987: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Info/SampleRate from Mixer
1804 245844204996: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Control from 0001f20000015a02
1805 245844205003: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element ConfigRom from 0001f20000015a02
1806 245844205009: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Generic from 0001f20000015a02
1807 245844205013: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element ClockSelect from Generic
1808 245844205018: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element SamplerateSelect from Generic
1809 245844205023: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element Nickname from Generic
1810 245844205027: Debug (Element.cpp)[ 279] deleteElementNoLock: Deleting Element StreamingStatus from Generic
1811 245844205044: Debug (IsoHandlerManager.cpp)[1080] stopHandlers: enter...
1812 245844205047: Debug (IsoHandlerManager.cpp)[ 936] pruneHandlers: enter...
1813 245844205052: Debug (PosixThread.cpp)[ 190] Stop: (ISOXMT) Stop 0x1bcbab0 (thread: 0x7fda87521910)
1814 245844208947: Debug (IsoHandlerManager.cpp)[ 134] updateShadowMapHelper: (0x1bcbb30) updating shadow vars...
1815 245844208955: Debug (IsoHandlerManager.cpp)[ 190] updateShadowMapHelper: (0x1bcbb30) updated shadow vars...
1816 245844211243: Debug (PosixThread.cpp)[  90] ThreadHandler: (ISOXMT) ThreadHandler: exit 0x1bcbab0
1817 245844211278: Debug (PosixThread.cpp)[ 197] Stop: (ISOXMT) Stopped 0x1bcbab0 (thread: (nil))
1818 245844211285: Debug (PosixThread.cpp)[ 190] Stop: (ISORCV) Stop 0x1bcbcd0 (thread: 0x7fda86d20910)
1819 245844218965: Debug (PosixThread.cpp)[  90] ThreadHandler: (ISORCV) ThreadHandler: exit 0x1bcbcd0
1820 245844218987: Debug (PosixThread.cpp)[ 197] Stop: (ISORCV) Stopped 0x1bcbcd0 (thread: (nil))
1821 245844218996: Debug (PosixThread.cpp)[ 190] Stop: (CTRHLP) Stop 0x1bcb6a0 (thread: 0x7fda87d22910)
1822 jack: 5402:245844203476 engine.c:do_request:1350: status of request: 0
1823 jack: 5402:245844203478 engine.c:do_request:1218: got a request of type 2
1824 jack: 5402:245844203480 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1825 jack: 5402:245844203483 engine.c:jack_port_do_unregister:3903: release graph lock
1826 jack: 5402:245844203484 engine.c:do_request:1350: status of request: 0
1827 jack: 5402:245844203486 engine.c:do_request:1218: got a request of type 2
1828 jack: 5402:245844203488 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1829 jack: 5402:245844203491 engine.c:jack_port_do_unregister:3903: release graph lock
1830 jack: 5402:245844203493 engine.c:do_request:1350: status of request: 0
1831 jack: 5402:245844203494 engine.c:do_request:1218: got a request of type 2
1832 jack: 5402:245844203496 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1833 jack: 5402:245844203499 engine.c:jack_port_do_unregister:3903: release graph lock
1834 jack: 5402:245844203501 engine.c:do_request:1350: status of request: 0
1835 jack: 5402:245844203503 engine.c:do_request:1218: got a request of type 2
1836 jack: 5402:245844203505 engine.c:jack_port_do_unregister:3886: acquiring graph write lock
1837 jack: 5402:245844203507 engine.c:jack_port_do_unregister:3903: release graph lock
1838 jack: 5402:245844203509 engine.c:do_request:1350: status of request: 0
1839 245844415341: Debug (PosixThread.cpp)[  90] ThreadHandler: (CTRHLP) ThreadHandler: exit 0x1bcb6a0
1840 245844415387: Debug (PosixThread.cpp)[ 197] Stop: (CTRHLP) Stopped 0x1bcb6a0 (thread: (nil))
1841 245844415402: Debug (ieee1394service.cpp)[1233] remBusResetHandler: Removing busreset handler (0x1bcb850)
1842 245844415407: Debug (ieee1394service.cpp)[1240] remBusResetHandler:  found
1843 245844415423: Debug (PosixThread.cpp)[ 190] Stop: (BUSRST) Stop 0x1bc89c0 (thread: 0x7fda89525910)
1844 245844415452: Debug (PosixThread.cpp)[  90] ThreadHandler: (BUSRST) ThreadHandler: exit 0x1bc89c0
1845 245844415502: Debug (PosixThread.cpp)[ 197] Stop: (BUSRST) Stopped 0x1bc89c0 (thread: (nil))
1846 245844415516: Debug (PosixThread.cpp)[ 190] Stop: (ARMSTD) Stop 0x1bcafe0 (thread: 0x7fda88d24910)
1847 245844415527: Debug (PosixThread.cpp)[  90] ThreadHandler: (ARMSTD) ThreadHandler: exit 0x1bcafe0
1848 245844419798: Debug (PosixThread.cpp)[ 197] Stop: (ARMSTD) Stopped 0x1bcafe0 (thread: (nil))
1849 245844419859: Debug (PosixThread.cpp)[ 190] Stop: (ARMRT) Stop 0x1bcb0f0 (thread: 0x7fda88523910)
1850 245844420869: Debug (PosixThread.cpp)[  90] ThreadHandler: (ARMRT) ThreadHandler: exit 0x1bcb0f0
1851 245844424775: Debug (PosixThread.cpp)[ 197] Stop: (ARMRT) Stopped 0x1bcb0f0 (thread: (nil))
1852 245844424789: Debug (PosixThread.cpp)[ 174] Kill: (WDGCHK) Kill 0x1bc8bb0 (thread: 0x7fda89d26910)
1853 245844428994: Debug (PosixThread.cpp)[ 180] Kill: (WDGCHK) Killed 0x1bc8bb0 (thread: 0x7fda89d26910)
1854 245844429053: Debug (PosixThread.cpp)[ 174] Kill: (WDGHBT) Kill 0x1bc8ac0 (thread: 0x7fda8a527910)
1855 245844433100: Debug (PosixThread.cpp)[ 180] Kill: (WDGHBT) Killed 0x1bc8ac0 (thread: 0x7fda8a527910)
1856 no message buffer overruns
1857 ERROR: messagebuffer not initialized: jack: 5402:245844453559 ../libjack/client.c:default_jack_error_callback:210: WARNING: 4 message buffer overruns!root@ubuntu-studio:/home/sczjd#
1858
1859