root/branches/api-cleanup/src/libstreaming/generic/StreamProcessor.cpp

Revision 816, 67.1 kB (checked in by ppalmers, 14 years ago)

remove support for per-port datatypes. It's too much hassle and it doesn't add enough value.
It also prevents thorough performance optimizations, especially for larger channel counts (e.g. SSE based).

Audio ports are now either all float or all int24. This can be specified by the ffado_streaming_set_audio_datatype
API function before the streaming is prepared. Hence we can still support the direct conversion to the
clients datatype when demuxing the packets.

Line 
1 /*
2  * Copyright (C) 2005-2007 by Pieter Palmers
3  *
4  * This file is part of FFADO
5  * FFADO = Free Firewire (pro-)audio drivers for linux
6  *
7  * FFADO is based upon FreeBoB.
8  *
9  * This program is free software: you can redistribute it and/or modify
10  * it under the terms of the GNU General Public License as published by
11  * the Free Software Foundation, either version 3 of the License, or
12  * (at your option) any later version.
13  *
14  * This program is distributed in the hope that it will be useful,
15  * but WITHOUT ANY WARRANTY; without even the implied warranty of
16  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
17  * GNU General Public License for more details.
18  *
19  * You should have received a copy of the GNU General Public License
20  * along with this program.  If not, see <http://www.gnu.org/licenses/>.
21  *
22  */
23
24 #include "config.h"
25
26 #include "StreamProcessor.h"
27 #include "../StreamProcessorManager.h"
28
29 #include "devicemanager.h"
30
31 #include "libieee1394/ieee1394service.h"
32 #include "libieee1394/IsoHandlerManager.h"
33 #include "libieee1394/cycletimer.h"
34
35 #include "libutil/Time.h"
36
37 #include "libutil/Atomic.h"
38
39 #include <assert.h>
40 #include <math.h>
41
42 /*
43 #define POST_SEMAPHORE { \
44     int tmp; \
45     sem_getvalue(&m_signal_semaphore, &tmp); \
46     debugWarning("posting semaphore from value %d\n", tmp); \
47     sem_post(&m_signal_semaphore); \
48 }
49 */
50
51 #define POST_SEMAPHORE { \
52     sem_post(&m_signal_semaphore); \
53 }
54
55 namespace Streaming {
56
57 IMPL_DEBUG_MODULE( StreamProcessor, StreamProcessor, DEBUG_LEVEL_VERBOSE );
58
59 StreamProcessor::StreamProcessor(FFADODevice &parent, enum eProcessorType type)
60     : m_processor_type ( type )
61     , m_state( ePS_Created )
62     , m_next_state( ePS_Invalid )
63     , m_cycle_to_switch_state( 0 )
64     , m_Parent( parent )
65     , m_1394service( parent.get1394Service() ) // local cache
66     , m_IsoHandlerManager( parent.get1394Service().getIsoHandlerManager() ) // local cache
67     , m_StreamProcessorManager( m_Parent.getDeviceManager().getStreamProcessorManager() ) // local cache
68     , m_channel( -1 )
69     , m_dropped(0)
70     , m_last_timestamp(0)
71     , m_last_timestamp2(0)
72     , m_scratch_buffer( NULL )
73     , m_scratch_buffer_size_bytes( 0 )
74     , m_ticks_per_frame( 0 )
75     , m_last_cycle( -1 )
76     , m_sync_delay( 0 )
77     , m_in_xrun( false )
78     , m_signal_period( 0 )
79     , m_signal_offset( 0 )
80 {
81     // create the timestamped buffer and register ourselves as its client
82     m_data_buffer = new Util::TimestampedBuffer(this);
83 }
84
85 StreamProcessor::~StreamProcessor() {
86     m_StreamProcessorManager.unregisterProcessor(this);
87     if(!m_IsoHandlerManager.unregisterStream(this)) {
88         debugOutput(DEBUG_LEVEL_VERBOSE,"Could not unregister stream processor with the Iso manager\n");
89     }
90     // make the threads leave the wait condition
91     POST_SEMAPHORE;
92     sem_destroy(&m_signal_semaphore);
93
94     if (m_data_buffer) delete m_data_buffer;
95     if (m_scratch_buffer) delete[] m_scratch_buffer;
96 }
97
98 uint64_t StreamProcessor::getTimeNow() {
99     return m_1394service.getCycleTimerTicks();
100 }
101
102 int StreamProcessor::getMaxFrameLatency() {
103     if (getType() == ePT_Receive) {
104         return (int)(m_IsoHandlerManager.getPacketLatencyForStream( this ) * TICKS_PER_CYCLE);
105     } else {
106         return (int)(m_IsoHandlerManager.getPacketLatencyForStream( this ) * TICKS_PER_CYCLE);
107     }
108 }
109
110 unsigned int
111 StreamProcessor::getNominalPacketsNeeded(unsigned int nframes)
112 {
113     unsigned int nominal_frames_per_second
114                     = m_StreamProcessorManager.getNominalRate();
115     uint64_t nominal_ticks_per_frame = TICKS_PER_SECOND / nominal_frames_per_second;
116     uint64_t nominal_ticks = nominal_ticks_per_frame * nframes;
117     uint64_t nominal_packets = nominal_ticks / TICKS_PER_CYCLE;
118     return nominal_packets;
119 }
120
121 unsigned int
122 StreamProcessor::getPacketsPerPeriod()
123 {
124     return getNominalPacketsNeeded(m_StreamProcessorManager.getPeriodSize());
125 }
126
127 unsigned int
128 StreamProcessor::getNbPacketsIsoXmitBuffer()
129 {
130 #if ISOHANDLER_PER_HANDLER_THREAD
131     // if we use one thread per packet, we can put every frame directly into the ISO buffer
132     // the waitForClient in IsoHandler will take care of the fact that the frames are
133     // not present in time
134     unsigned int packets_to_prebuffer = (getPacketsPerPeriod() * (m_StreamProcessorManager.getNbBuffers()));
135     debugOutput(DEBUG_LEVEL_VERBOSE, "Nominal prebuffer: %u\n", packets_to_prebuffer);
136     return packets_to_prebuffer;
137 #else
138     // the target is to have all of the transmit buffer (at period transfer) as ISO packets
139     // when one period is received, there will be approx (NbBuffers - 1) * period_size frames
140     // in the transmit buffer (the others are still to be put into the xmit frame buffer)
141     unsigned int packets_to_prebuffer = (getPacketsPerPeriod() * (m_StreamProcessorManager.getNbBuffers()-1));
142     debugOutput(DEBUG_LEVEL_VERBOSE, "Nominal prebuffer: %u\n", packets_to_prebuffer);
143    
144     // however we have to take into account the fact that there is some sync delay
145     // we assume that the SPM has indicated
146     // HACK: this counts on the fact that the latency for this stream will be the same as the
147     //       latency for the receive sync source
148     unsigned int est_sync_delay = getPacketsPerPeriod() / MINIMUM_INTERRUPTS_PER_PERIOD;
149     est_sync_delay += STREAMPROCESSORMANAGER_SIGNAL_DELAY_TICKS / TICKS_PER_CYCLE;
150     packets_to_prebuffer -= est_sync_delay;
151     debugOutput(DEBUG_LEVEL_VERBOSE, " correct for sync delay (%d): %u\n",
152                                      est_sync_delay,
153                                      packets_to_prebuffer);
154    
155     // only queue a part of the theoretical max in order not to have too much 'not ready' cycles
156     packets_to_prebuffer = (packets_to_prebuffer * MAX_ISO_XMIT_BUFFER_FILL_PCT * 1000) / 100000;
157     debugOutput(DEBUG_LEVEL_VERBOSE, " reduce to %d%%: %u\n",
158                                      MAX_ISO_XMIT_BUFFER_FILL_PCT, packets_to_prebuffer);
159    
160     return packets_to_prebuffer;
161 #endif
162 }
163
164 /***********************************************
165  * Buffer management and manipulation          *
166  ***********************************************/
167 void StreamProcessor::flush() {
168     m_IsoHandlerManager.flushHandlerForStream(this);
169 }
170
171 int StreamProcessor::getBufferFill() {
172     return m_data_buffer->getBufferFill();
173 }
174
175 int64_t
176 StreamProcessor::getTimeUntilNextPeriodSignalUsecs()
177 {
178     uint64_t time_at_period=getTimeAtPeriod();
179
180     // we delay the period signal with the sync delay
181     // this makes that the period signals lag a little compared to reality
182     // ISO buffering causes the packets to be received at max
183     // m_handler->getWakeupInterval() later than the time they were received.
184     // hence their payload is available this amount of time later. However, the
185     // period boundary is predicted based upon earlier samples, and therefore can
186     // pass before these packets are processed. Adding this extra term makes that
187     // the period boundary is signalled later
188     time_at_period = addTicks(time_at_period, m_StreamProcessorManager.getSyncSource().getSyncDelay());
189
190     uint64_t cycle_timer=m_1394service.getCycleTimerTicks();
191
192     // calculate the time until the next period
193     int32_t until_next=diffTicks(time_at_period,cycle_timer);
194
195     debugOutput(DEBUG_LEVEL_VERY_VERBOSE, "=> TAP=%11llu, CTR=%11llu, UTN=%11ld\n",
196         time_at_period, cycle_timer, until_next
197         );
198
199     // now convert to usecs
200     // don't use the mapping function because it only works
201     // for absolute times, not the relative time we are
202     // using here (which can also be negative).
203     return (int64_t)(((float)until_next) / TICKS_PER_USEC);
204 }
205
206 void
207 StreamProcessor::setSyncDelay(int d) {
208     debugOutput(DEBUG_LEVEL_ULTRA_VERBOSE, "Setting SP %p SyncDelay to %d ticks\n", this, d);
209     m_sync_delay = d;
210 }
211
212 uint64_t
213 StreamProcessor::getTimeAtPeriodUsecs()
214 {
215     return (uint64_t)((float)getTimeAtPeriod() * TICKS_PER_USEC);
216 }
217
218 uint64_t
219 StreamProcessor::getTimeAtPeriod()
220 {
221     if (getType() == ePT_Receive) {
222         ffado_timestamp_t next_period_boundary=m_data_buffer->getTimestampFromHead(m_StreamProcessorManager.getPeriodSize());
223    
224         #ifdef DEBUG
225         ffado_timestamp_t ts;
226         signed int fc;
227         m_data_buffer->getBufferTailTimestamp(&ts,&fc);
228    
229         debugOutput(DEBUG_LEVEL_VERY_VERBOSE, "=> NPD="TIMESTAMP_FORMAT_SPEC", LTS="TIMESTAMP_FORMAT_SPEC", FC=%5u, TPF=%f\n",
230             next_period_boundary, ts, fc, getTicksPerFrame()
231             );
232         #endif
233         return (uint64_t)next_period_boundary;
234     } else {
235         ffado_timestamp_t next_period_boundary=m_data_buffer->getTimestampFromTail((m_StreamProcessorManager.getNbBuffers()-1) * m_StreamProcessorManager.getPeriodSize());
236    
237         #ifdef DEBUG
238         ffado_timestamp_t ts;
239         signed int fc;
240         m_data_buffer->getBufferTailTimestamp(&ts,&fc);
241    
242         debugOutput(DEBUG_LEVEL_VERY_VERBOSE, "=> NPD="TIMESTAMP_FORMAT_SPEC", LTS="TIMESTAMP_FORMAT_SPEC", FC=%5u, TPF=%f\n",
243             next_period_boundary, ts, fc, getTicksPerFrame()
244             );
245         #endif
246         return (uint64_t)next_period_boundary;
247     }
248 }
249
250 float
251 StreamProcessor::getTicksPerFrame()
252 {
253     assert(m_data_buffer != NULL);
254     return m_data_buffer->getRate();
255 }
256
257 bool
258 StreamProcessor::canClientTransferFrames(unsigned int nbframes)
259 {
260     bool can_transfer;
261     unsigned int fc = m_data_buffer->getFrameCounter();
262     if (getType() == ePT_Receive) {
263         can_transfer = (fc >= nbframes);
264     } else {
265         // there has to be enough space to put the frames in
266         can_transfer = m_data_buffer->getBufferSize() - fc > nbframes;
267         // or the buffer is transparent
268         can_transfer |= m_data_buffer->isTransparent();
269     }
270    
271     #ifdef DEBUG
272     if (!can_transfer) {
273         debugWarning("(%p, %s) cannot transfer since fc == %u, nbframes == %u\n",
274             this, ePTToString(getType()), fc, nbframes);
275     }
276     #endif
277    
278     return can_transfer;
279 }
280
281 /***********************************************
282  * I/O API                                     *
283  ***********************************************/
284
285 // Packet transfer API
286 enum raw1394_iso_disposition
287 StreamProcessor::putPacket(unsigned char *data, unsigned int length,
288                            unsigned char channel, unsigned char tag, unsigned char sy,
289                            unsigned int cycle, unsigned int dropped) {
290     if(m_last_cycle == -1) {
291         debugOutput(DEBUG_LEVEL_VERBOSE, "Handler for %s SP %p is alive (cycle = %u)\n", getTypeString(), this, cycle);
292     }
293
294     int dropped_cycles = 0;
295     if (m_last_cycle != (int)cycle && m_last_cycle != -1) {
296         dropped_cycles = diffCycles(cycle, m_last_cycle) - 1;
297         if (dropped_cycles < 0) {
298             debugWarning("(%p) dropped < 1 (%d), cycle: %d, last_cycle: %d, dropped: %d\n",
299                          this, dropped_cycles, cycle, m_last_cycle, dropped);
300         }
301         if (dropped_cycles > 0) {
302             debugWarning("(%p) dropped %d packets on cycle %u, 'dropped'=%u, cycle=%d, m_last_cycle=%d\n",
303                 this, dropped_cycles, cycle, dropped, cycle, m_last_cycle);
304             m_dropped += dropped_cycles;
305             m_in_xrun = true;
306             m_last_cycle = cycle;
307             POST_SEMAPHORE;
308             return RAW1394_ISO_DEFER;
309             //flushDebugOutput();
310             //assert(0);
311         }
312     }
313     m_last_cycle = cycle;
314
315     // bypass based upon state
316     if (m_state == ePS_Invalid) {
317         debugError("Should not have state %s\n", ePSToString(m_state) );
318         POST_SEMAPHORE;
319         return RAW1394_ISO_ERROR;
320     }
321     if (m_state == ePS_Created) {
322         return RAW1394_ISO_DEFER;
323     }
324
325     // store the previous timestamp
326     m_last_timestamp2 = m_last_timestamp;
327
328     // NOTE: synchronized switching is restricted to a 0.5 sec span (4000 cycles)
329     //       it happens on the first 'good' cycle for the wait condition
330     //       or on the first received cycle that is received afterwards (might be a problem)
331
332     // check whether we are waiting for a stream to be disabled
333     if(m_state == ePS_WaitingForStreamDisable) {
334         // we then check whether we have to switch on this cycle
335         if (diffCycles(cycle, m_cycle_to_switch_state) >= 0) {
336             debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to DryRunning\n");
337             m_next_state = ePS_DryRunning;
338             if (!updateState()) { // we are allowed to change the state directly
339                 debugError("Could not update state!\n");
340                 POST_SEMAPHORE;
341                 return RAW1394_ISO_ERROR;
342             }
343         } else {
344             // not time to disable yet
345         }
346         // the received data can be discarded while waiting for the stream
347         // to be disabled
348         return RAW1394_ISO_OK;
349     }
350
351     // check whether we are waiting for a stream to be enabled
352     else if(m_state == ePS_WaitingForStreamEnable) {
353         // we then check whether we have to switch on this cycle
354         if (diffCycles(cycle, m_cycle_to_switch_state) >= 0) {
355             debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to Running\n");
356             m_next_state = ePS_Running;
357             if (!updateState()) { // we are allowed to change the state directly
358                 debugError("Could not update state!\n");
359                 POST_SEMAPHORE;
360                 return RAW1394_ISO_ERROR;
361             }
362         } else {
363             // not time to enable yet
364         }
365         // we are dryRunning hence data should be processed in any case
366     }
367
368     // check the packet header
369     enum eChildReturnValue result = processPacketHeader(data, length, channel, tag, sy, cycle, dropped_cycles);
370     if (result == eCRV_OK) {
371         debugOutput(DEBUG_LEVEL_VERY_VERBOSE, "RECV: CY=%04u TS=%011llu\n",
372                 cycle, m_last_timestamp);
373         // update some accounting
374         m_last_good_cycle = cycle;
375         m_last_dropped = dropped_cycles;
376
377         // check whether we are waiting for a stream to startup
378         // this requires that the packet is good
379         if(m_state == ePS_WaitingForStream) {
380             // since we have a packet with an OK header,
381             // we can indicate that the stream started up
382
383             // we then check whether we have to switch on this cycle
384             if (diffCycles(cycle, m_cycle_to_switch_state) >= 0) {
385                 debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to DryRunning due to good packet\n");
386                 // hence go to the dryRunning state
387                 m_next_state = ePS_DryRunning;
388                 if (!updateState()) { // we are allowed to change the state directly
389                     debugError("Could not update state!\n");
390                     POST_SEMAPHORE;
391                     return RAW1394_ISO_ERROR;
392                 }
393             } else {
394                 // not time (yet) to switch state
395             }
396             // in both cases we don't want to process the data
397             return RAW1394_ISO_OK;
398         }
399
400         // check whether a state change has been requested
401         // note that only the wait state changes are synchronized with the cycles
402         else if(m_state != m_next_state) {
403             debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state from %s to %s\n",
404                                              ePSToString(m_state), ePSToString(m_next_state));
405             // execute the requested change
406             if (!updateState()) { // we are allowed to change the state directly
407                 debugError("Could not update state!\n");
408                 POST_SEMAPHORE;
409                 return RAW1394_ISO_ERROR;
410             }
411         }
412
413         // handle dropped cycles
414         if(dropped_cycles) {
415             // they represent a discontinuity in the timestamps, and hence are
416             // to be dealt with
417             debugWarning("(%p) Correcting timestamp for dropped cycles, discarding packet...\n", this);
418             m_data_buffer->setBufferTailTimestamp(m_last_timestamp);
419             if (m_state == ePS_Running) {
420                 // this is an xrun situation
421                 m_in_xrun = true;
422                 debugWarning("Should update state to WaitingForStreamDisable due to dropped packet xrun\n");
423                 m_cycle_to_switch_state = cycle + 1; // switch in the next cycle
424                 m_next_state = ePS_WaitingForStreamDisable;
425                 // execute the requested change
426                 if (!updateState()) { // we are allowed to change the state directly
427                     debugError("Could not update state!\n");
428                     POST_SEMAPHORE;
429                     return RAW1394_ISO_ERROR;
430                 }
431                 POST_SEMAPHORE;
432                 return RAW1394_ISO_DEFER;
433             }
434         }
435
436         // for all states that reach this we are allowed to
437         // do protocol specific data reception
438         enum eChildReturnValue result2 = processPacketData(data, length, channel, tag, sy, cycle, dropped_cycles);
439
440         // if an xrun occured, switch to the dryRunning state and
441         // allow for the xrun to be picked up
442         if (result2 == eCRV_XRun) {
443             debugWarning("processPacketData xrun\n");
444             m_in_xrun = true;
445             debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to WaitingForStreamDisable due to data xrun\n");
446             m_cycle_to_switch_state = cycle+1; // switch in the next cycle
447             m_next_state = ePS_WaitingForStreamDisable;
448             // execute the requested change
449             if (!updateState()) { // we are allowed to change the state directly
450                 debugError("Could not update state!\n");
451                 POST_SEMAPHORE;
452                 return RAW1394_ISO_ERROR;
453             }
454             POST_SEMAPHORE;
455             return RAW1394_ISO_DEFER;
456         } else if(result2 == eCRV_OK) {
457             // no problem here
458             // if we have enough samples, we can post the semaphore and
459             // defer further processing until later. this will allow us to
460             // run the client and process the frames such that we can put them
461             // into the xmit buffers ASAP
462             if (m_state == ePS_Running) {
463                 unsigned int bufferfill = m_data_buffer->getBufferFill();
464                 if(bufferfill >= m_signal_period + m_signal_offset) {
465                     // this to avoid multiple signals for the same period
466                     int semval;
467                     sem_getvalue(&m_signal_semaphore, &semval);
468                     unsigned int signal_period = m_signal_period * (semval + 1) + m_signal_offset;
469                     if(bufferfill >= signal_period) {
470                         debugOutput(DEBUG_LEVEL_VERBOSE, "(%p) buffer fill (%d) > signal period (%d), sem_val=%d\n",
471                                     this, m_data_buffer->getBufferFill(), signal_period, semval);
472                         POST_SEMAPHORE;
473                     }
474                     // the process thread should have higher prio such that we are blocked until
475                     // the samples are processed.
476                     return RAW1394_ISO_DEFER;
477                 }
478             }
479             return RAW1394_ISO_OK;
480         } else {
481             debugError("Invalid response\n");
482             POST_SEMAPHORE;
483             return RAW1394_ISO_ERROR;
484         }
485     } else if(result == eCRV_Invalid) {
486         // apparently we don't have to do anything when the packets are not valid
487         return RAW1394_ISO_OK;
488     } else {
489         debugError("Invalid response\n");
490         POST_SEMAPHORE;
491         return RAW1394_ISO_ERROR;
492     }
493     debugError("reached the unreachable\n");
494     POST_SEMAPHORE;
495     return RAW1394_ISO_ERROR;
496 }
497
498 enum raw1394_iso_disposition
499 StreamProcessor::getPacket(unsigned char *data, unsigned int *length,
500                            unsigned char *tag, unsigned char *sy,
501                            int cycle, unsigned int dropped, unsigned int max_length) {
502     if (cycle<0) {
503         *tag = 0;
504         *sy = 0;
505         *length = 0;
506         return RAW1394_ISO_OK;
507     }
508
509     unsigned int ctr;
510     int now_cycles;
511     int cycle_diff;
512
513     if(m_last_cycle == -1) {
514         debugOutput(DEBUG_LEVEL_VERBOSE, "Handler for %s SP %p is alive (cycle = %d)\n", getTypeString(), this, cycle);
515     }
516
517     int dropped_cycles = 0;
518     if (m_last_cycle != cycle && m_last_cycle != -1) {
519         dropped_cycles = diffCycles(cycle, m_last_cycle) - 1;
520         if (dropped_cycles < 0) {
521             debugWarning("(%p) dropped < 1 (%d), cycle: %d, last_cycle: %d, dropped: %d\n",
522                          this, dropped_cycles, cycle, m_last_cycle, dropped);
523         }
524         if (dropped_cycles > 0) {
525             debugWarning("(%p) dropped %d packets on cycle %u (last_cycle=%u, dropped=%d)\n", this, dropped_cycles, cycle, m_last_cycle, dropped);
526             m_dropped += dropped_cycles;
527             // HACK: this should not be necessary, since the header generation functions should trigger the xrun.
528             //       but apparently there are some issues with the 1394 stack
529             m_in_xrun = true;
530             if(m_state == ePS_Running) {
531                 debugShowBackLogLines(200);
532                 debugWarning("dropped packets xrun\n");
533                 debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to WaitingForStreamDisable due to dropped packets xrun\n");
534                 m_next_state = ePS_WaitingForStreamDisable;
535                 // execute the requested change
536                 if (!updateState()) { // we are allowed to change the state directly
537                     debugError("Could not update state!\n");
538                     return RAW1394_ISO_ERROR;
539                 }
540                 goto send_empty_packet;
541             }
542         }
543     }
544     if (cycle >= 0) {
545         m_last_cycle = cycle;
546     }
547
548     // bypass based upon state
549     if (m_state == ePS_Invalid) {
550         debugError("Should not have state %s\n", ePSToString(m_state) );
551         return RAW1394_ISO_ERROR;
552     }
553     if (m_state == ePS_Created) {
554         *tag = 0;
555         *sy = 0;
556         *length = 0;
557         return RAW1394_ISO_DEFER;
558     }
559
560     // normal processing
561     // note that we can't use getCycleTimer directly here,
562     // because packets are queued in advance. This means that
563     // we the packet we are constructing will be sent out
564     // on 'cycle', not 'now'.
565     ctr = m_1394service.getCycleTimer();
566     now_cycles = (int)CYCLE_TIMER_GET_CYCLES(ctr);
567
568     // the difference between the cycle this
569     // packet is intended for and 'now'
570     cycle_diff = diffCycles(cycle, now_cycles);
571
572     if(cycle_diff < 0 && (m_state == ePS_Running || m_state == ePS_DryRunning)) {
573         debugWarning("Requesting packet for cycle %04d which is in the past (now=%04dcy)\n",
574             cycle, now_cycles);
575         if(m_state == ePS_Running) {
576             debugShowBackLogLines(200);
577 //             flushDebugOutput();
578 //             assert(0);
579             debugWarning("generatePacketData xrun\n");
580             m_in_xrun = true;
581             debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to WaitingForStreamDisable due to data xrun\n");
582             m_next_state = ePS_WaitingForStreamDisable;
583             // execute the requested change
584             if (!updateState()) { // we are allowed to change the state directly
585                 debugError("Could not update state!\n");
586                 return RAW1394_ISO_ERROR;
587             }
588             goto send_empty_packet;
589         }
590     }
591
592     // store the previous timestamp
593     m_last_timestamp2 = m_last_timestamp;
594
595     // NOTE: synchronized switching is restricted to a 0.5 sec span (4000 cycles)
596     //       it happens on the first 'good' cycle for the wait condition
597     //       or on the first received cycle that is received afterwards (might be a problem)
598
599     // check whether we are waiting for a stream to be disabled
600     if(m_state == ePS_WaitingForStreamDisable) {
601         // we then check whether we have to switch on this cycle
602         if (diffCycles(cycle, m_cycle_to_switch_state) >= 0) {
603             debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to DryRunning\n");
604             m_next_state = ePS_DryRunning;
605             if (!updateState()) { // we are allowed to change the state directly
606                 debugError("Could not update state!\n");
607                 return RAW1394_ISO_ERROR;
608             }
609         } else {
610             // not time to disable yet
611         }
612     }
613     // check whether we are waiting for a stream to be enabled
614     else if(m_state == ePS_WaitingForStreamEnable) {
615         // we then check whether we have to switch on this cycle
616         if (diffCycles(cycle, m_cycle_to_switch_state) >= 0) {
617             debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to Running\n");
618             m_next_state = ePS_Running;
619             if (!updateState()) { // we are allowed to change the state directly
620                 debugError("Could not update state!\n");
621                 return RAW1394_ISO_ERROR;
622             }
623         } else {
624             // not time to enable yet
625         }
626         // we are dryRunning hence data should be processed in any case
627     }
628     // check whether we are waiting for a stream to startup
629     else if(m_state == ePS_WaitingForStream) {
630         // as long as the cycle parameter is not in sync with
631         // the current time, the stream is considered not
632         // to be 'running'
633         // we then check whether we have to switch on this cycle
634         if ((cycle_diff >= 0) && (diffCycles(cycle, m_cycle_to_switch_state) >= 0)) {
635             debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to WaitingForStream to DryRunning\n");
636             // hence go to the dryRunning state
637             m_next_state = ePS_DryRunning;
638             if (!updateState()) { // we are allowed to change the state directly
639                 debugError("Could not update state!\n");
640                 return RAW1394_ISO_ERROR;
641             }
642         } else {
643             // not time (yet) to switch state
644         }
645     }
646     else if(m_state == ePS_Running) {
647         // check the packet header
648         enum eChildReturnValue result = generatePacketHeader(data, length, tag, sy, cycle, dropped_cycles, max_length);
649         if (result == eCRV_Packet || result == eCRV_Defer) {
650             debugOutput(DEBUG_LEVEL_VERY_VERBOSE, "XMIT: CY=%04u TS=%011llu\n",
651                     cycle, m_last_timestamp);
652             // update some accounting
653             m_last_good_cycle = cycle;
654             m_last_dropped = dropped_cycles;
655
656             // check whether a state change has been requested
657             // note that only the wait state changes are synchronized with the cycles
658             if(m_state != m_next_state) {
659                 debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state from %s to %s\n",
660                                                 ePSToString(m_state), ePSToString(m_next_state));
661                 // execute the requested change
662                 if (!updateState()) { // we are allowed to change the state directly
663                     debugError("Could not update state!\n");
664                     return RAW1394_ISO_ERROR;
665                 }
666             }
667
668             enum eChildReturnValue result2 = generatePacketData(data, length, tag, sy, cycle, dropped_cycles, max_length);
669             // if an xrun occured, switch to the dryRunning state and
670             // allow for the xrun to be picked up
671             if (result2 == eCRV_XRun) {
672                 debugWarning("generatePacketData xrun\n");
673                 m_in_xrun = true;
674                 debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to WaitingForStreamDisable due to data xrun\n");
675                 m_cycle_to_switch_state = cycle+1; // switch in the next cycle
676                 m_next_state = ePS_WaitingForStreamDisable;
677                 // execute the requested change
678                 if (!updateState()) { // we are allowed to change the state directly
679                     debugError("Could not update state!\n");
680                     return RAW1394_ISO_ERROR;
681                 }
682                 goto send_empty_packet;
683             }
684             // skip queueing packets if we detect that there are not enough frames
685             // available
686             if(result2 == eCRV_Defer || result == eCRV_Defer)
687                 return RAW1394_ISO_DEFER;
688             else
689                 return RAW1394_ISO_OK;
690         } else if (result == eCRV_XRun) { // pick up the possible xruns
691             debugWarning("generatePacketHeader xrun\n");
692             m_in_xrun = true;
693             debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to WaitingForStreamDisable due to header xrun\n");
694             m_next_state = ePS_WaitingForStreamDisable;
695             // execute the requested change
696             if (!updateState()) { // we are allowed to change the state directly
697                 debugError("Could not update state!\n");
698                 return RAW1394_ISO_ERROR;
699             }
700         } else if (result == eCRV_EmptyPacket) {
701             if(m_state != m_next_state) {
702                 debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state from %s to %s\n",
703                                                 ePSToString(m_state), ePSToString(m_next_state));
704                 // execute the requested change
705                 if (!updateState()) { // we are allowed to change the state directly
706                     debugError("Could not update state!\n");
707                     return RAW1394_ISO_ERROR;
708                 }
709             }
710             goto send_empty_packet;
711         } else if (result == eCRV_Again) {
712             debugOutput(DEBUG_LEVEL_VERY_VERBOSE, "have to retry cycle %d\n", cycle);
713             if(m_state != m_next_state) {
714                 debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state from %s to %s\n",
715                                                 ePSToString(m_state), ePSToString(m_next_state));
716                 // execute the requested change
717                 if (!updateState()) { // we are allowed to change the state directly
718                     debugError("Could not update state!\n");
719                     return RAW1394_ISO_ERROR;
720                 }
721             }
722             usleep(125); // only when using thread-per-handler
723             return RAW1394_ISO_AGAIN;
724 //             generateSilentPacketHeader(data, length, tag, sy, cycle, dropped_cycles, max_length);
725 //             generateSilentPacketData(data, length, tag, sy, cycle, dropped_cycles, max_length);
726 //             return RAW1394_ISO_DEFER;
727         } else {
728             debugError("Invalid return value: %d\n", result);
729             return RAW1394_ISO_ERROR;
730         }
731     }
732     // we are not running, so send an empty packet
733     // we should generate a valid packet any time
734 send_empty_packet:
735     // note that only the wait state changes are synchronized with the cycles
736     if(m_state != m_next_state) {
737         debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state from %s to %s\n",
738                                         ePSToString(m_state), ePSToString(m_next_state));
739         // execute the requested change
740         if (!updateState()) { // we are allowed to change the state directly
741             debugError("Could not update state!\n");
742             return RAW1394_ISO_ERROR;
743         }
744     }
745
746     debugOutput(DEBUG_LEVEL_VERY_VERBOSE, "XMIT EMPTY: CY=%04u\n", cycle);
747     generateSilentPacketHeader(data, length, tag, sy, cycle, dropped_cycles, max_length);
748     generateSilentPacketData(data, length, tag, sy, cycle, dropped_cycles, max_length);
749     return RAW1394_ISO_OK;
750 }
751
752
753 // Frame Transfer API
754 /**
755  * Transfer a block of frames from the event buffer to the port buffers
756  * @param nbframes number of frames to transfer
757  * @param ts the timestamp that the LAST frame in the block should have
758  * @return
759  */
760 bool StreamProcessor::getFrames(unsigned int nbframes, int64_t ts) {
761     debugOutput( DEBUG_LEVEL_VERY_VERBOSE, "%p.getFrames(%d, %11llu)", nbframes, ts);
762     assert( getType() == ePT_Receive );
763     if(isDryRunning()) return getFramesDry(nbframes, ts);
764     else return getFramesWet(nbframes, ts);
765 }
766
767 bool StreamProcessor::getFramesWet(unsigned int nbframes, int64_t ts) {
768 // FIXME: this should be done somewhere else
769 #ifdef DEBUG
770     uint64_t ts_expected;
771     signed int fc;
772     int32_t lag_ticks;
773     float lag_frames;
774
775     // in order to sync up multiple received streams, we should
776     // use the ts parameter. It specifies the time of the block's
777     // last sample.
778     float srate = m_StreamProcessorManager.getSyncSource().getTicksPerFrame();
779     assert(srate != 0.0);
780     int64_t this_block_length_in_ticks = (int64_t)(((float)nbframes) * srate);
781
782     ffado_timestamp_t ts_head_tmp;
783     m_data_buffer->getBufferHeadTimestamp(&ts_head_tmp, &fc);
784     ts_expected = addTicks((uint64_t)ts_head_tmp, this_block_length_in_ticks);
785
786     lag_ticks = diffTicks(ts, ts_expected);
787     lag_frames = (((float)lag_ticks) / srate);
788     debugOutput( DEBUG_LEVEL_VERY_VERBOSE, "stream (%p): drifts %6d ticks = %10.5f frames (rate=%10.5f), %lld, %llu, %d\n",
789                  this, lag_ticks, lag_frames, srate, ts, ts_expected, fc);
790     if (lag_frames >= 1.0) {
791         // the stream lags
792         debugWarning( "stream (%p): lags  with %6d ticks = %10.5f frames (rate=%10.5f), %lld, %llu, %d\n",
793                       this, lag_ticks, lag_frames, srate, ts, ts_expected, fc);
794     } else if (lag_frames <= -1.0) {
795         // the stream leads
796         debugWarning( "stream (%p): leads with %6d ticks = %10.5f frames (rate=%10.5f), %lld, %llu, %d\n",
797                       this, lag_ticks, lag_frames, srate, ts, ts_expected, fc);
798     }
799 #endif
800     // ask the buffer to process nbframes of frames
801     // using it's registered client's processReadBlock(),
802     // which should be ours
803     m_data_buffer->blockProcessReadFrames(nbframes);
804     return true;
805 }
806
807 bool StreamProcessor::getFramesDry(unsigned int nbframes, int64_t ts)
808 {
809     debugOutput( DEBUG_LEVEL_VERY_VERBOSE, "stream (%p): dry run %d frames (@ ts=%lld)\n",
810                  this, nbframes, ts);
811     // dry run on this side means that we put silence in all enabled ports
812     // since there is do data put into the ringbuffer in the dry-running state
813     return provideSilenceBlock(nbframes, 0);
814 }
815
816 bool
817 StreamProcessor::dropFrames(unsigned int nbframes, int64_t ts)
818 {
819     debugOutput(DEBUG_LEVEL_VERY_VERBOSE, "StreamProcessor::dropFrames(%d, %lld)\n", nbframes, ts);
820     return m_data_buffer->dropFrames(nbframes);
821 }
822
823 bool StreamProcessor::putFrames(unsigned int nbframes, int64_t ts)
824 {
825     debugOutput( DEBUG_LEVEL_VERY_VERBOSE, "%p.putFrames(%d, %11llu)", nbframes, ts);
826     assert( getType() == ePT_Transmit );
827
828     if(isDryRunning()) return putFramesDry(nbframes, ts);
829     else return putFramesWet(nbframes, ts);
830 }
831
832 bool
833 StreamProcessor::putFramesWet(unsigned int nbframes, int64_t ts)
834 {
835     debugOutput(DEBUG_LEVEL_ULTRA_VERBOSE, "StreamProcessor::putFramesWet(%d, %llu)\n", nbframes, ts);
836     // transfer the data
837     m_data_buffer->blockProcessWriteFrames(nbframes, ts);
838     debugOutput(DEBUG_LEVEL_ULTRA_VERBOSE, " New timestamp: %llu\n", ts);
839
840     unsigned int bufferfill = m_data_buffer->getBufferFill();
841     if (bufferfill >= m_signal_period + m_signal_offset) {
842         debugOutput(DEBUG_LEVEL_VERBOSE, "(%p) sufficient frames in buffer (%d / %d), posting semaphore\n",
843                                          this, bufferfill, m_signal_period + m_signal_offset);
844         POST_SEMAPHORE;
845     } else {
846         debugOutput(DEBUG_LEVEL_VERBOSE, "(%p) insufficient frames in buffer (%d / %d), not posting semaphore\n",
847                                          this, bufferfill, m_signal_period + m_signal_offset);
848     }
849     return true; // FIXME: what about failure?
850 }
851
852 bool
853 StreamProcessor::putFramesDry(unsigned int nbframes, int64_t ts)
854 {
855     debugOutput(DEBUG_LEVEL_ULTRA_VERBOSE, "StreamProcessor::putFramesDry(%d, %llu)\n", nbframes, ts);
856     // do nothing
857     return true;
858 }
859
860 bool
861 StreamProcessor::putSilenceFrames(unsigned int nbframes, int64_t ts)
862 {
863     debugOutput(DEBUG_LEVEL_ULTRA_VERBOSE, "StreamProcessor::putSilenceFrames(%d, %llu)\n", nbframes, ts);
864
865     size_t bytes_per_frame = getEventSize() * getEventsPerFrame();
866     unsigned int scratch_buffer_size_frames = m_scratch_buffer_size_bytes / bytes_per_frame;
867
868     if (nbframes > scratch_buffer_size_frames) {
869         debugError("nframes (%u) > scratch_buffer_size_frames (%u)\n",
870                    nbframes, scratch_buffer_size_frames);
871     }
872
873     assert(m_scratch_buffer);
874     if(!transmitSilenceBlock((char *)m_scratch_buffer, nbframes, 0)) {
875         debugError("Could not prepare silent block\n");
876         return false;
877     }
878     if(!m_data_buffer->writeFrames(nbframes, (char *)m_scratch_buffer, ts)) {
879         debugError("Could not write silent block\n");
880         return false;
881     }
882
883     unsigned int bufferfill = m_data_buffer->getBufferFill();
884     if (bufferfill >= m_signal_period + m_signal_offset) {
885         debugOutput(DEBUG_LEVEL_VERBOSE, "(%p) sufficient frames in buffer (%d / %d), posting semaphore\n",
886                                          this, bufferfill, m_signal_period + m_signal_offset);
887         POST_SEMAPHORE;
888     } else {
889         debugOutput(DEBUG_LEVEL_VERBOSE, "(%p) insufficient frames in buffer (%d / %d), not posting semaphore\n",
890                                          this, bufferfill, m_signal_period + m_signal_offset);
891     }
892
893     return true;
894 }
895
896 bool
897 StreamProcessor::waitForSignal()
898 {
899     int result;
900     if(m_state == ePS_Running) {
901         result = sem_wait(&m_signal_semaphore);
902 #ifdef DEBUG
903         int tmp;
904         sem_getvalue(&m_signal_semaphore, &tmp);
905         debugOutput(DEBUG_LEVEL_VERBOSE, " sem_wait returns: %d, sem_value: %d\n", result, tmp);
906 #endif
907         return result == 0;
908     } else {
909         // when we're not running, we can always provide frames
910         debugOutput(DEBUG_LEVEL_VERBOSE, "Not running...\n");
911         return true;
912     }
913 }
914
915 bool
916 StreamProcessor::tryWaitForSignal()
917 {
918     if(m_state == ePS_Running) {
919         return sem_trywait(&m_signal_semaphore) == 0;
920     } else {
921         // when we're not running, we can always provide frames
922         debugOutput(DEBUG_LEVEL_VERY_VERBOSE, "Not running...\n");
923         return true;
924     }
925 }
926
927 bool
928 StreamProcessor::canProcessPackets()
929 {
930     if(m_state != ePS_Running) return true;
931     bool result;
932     int bufferfill;
933     if(getType() == ePT_Receive) {
934         bufferfill = m_data_buffer->getBufferSpace();
935     } else {
936         bufferfill = m_data_buffer->getBufferFill();
937     }
938     result = bufferfill > getNominalFramesPerPacket();
939     // debugOutput(DEBUG_LEVEL_VERBOSE, "(%p, %s) for a bufferfill of %d, we return %d\n",
940     //             this, ePTToString(getType()), bufferfill, result);
941     return result;
942 }
943
944 bool
945 StreamProcessor::shiftStream(int nbframes)
946 {
947     if(nbframes == 0) return true;
948     if(nbframes > 0) {
949         return m_data_buffer->dropFrames(nbframes);
950     } else {
951         bool result = true;
952         while(nbframes++) {
953             result &= m_data_buffer->writeDummyFrame();
954         }
955         return result;
956     }
957 }
958
959 /**
960  * @brief write silence events to the stream ringbuffers.
961  */
962 bool StreamProcessor::provideSilenceBlock(unsigned int nevents, unsigned int offset)
963 {
964     bool no_problem=true;
965     for ( PortVectorIterator it = m_Ports.begin();
966           it != m_Ports.end();
967           ++it ) {
968         if((*it)->isDisabled()) {continue;};
969
970         if(provideSilenceToPort((*it), offset, nevents)) {
971             debugWarning("Could not put silence into to port %s",(*it)->getName().c_str());
972             no_problem=false;
973         }
974     }
975     return no_problem;
976 }
977
978 int
979 StreamProcessor::provideSilenceToPort(Port *p, unsigned int offset, unsigned int nevents)
980 {
981     unsigned int j=0;
982     switch(p->getPortType()) {
983         default:
984             debugError("Invalid port type: %d\n", p->getPortType());
985             return -1;
986         case Port::E_Midi:
987         case Port::E_Control:
988             {
989                 quadlet_t *buffer=(quadlet_t *)(p->getBufferAddress());
990                 assert(nevents + offset <= p->getBufferSize());
991                 buffer+=offset;
992
993                 for(j = 0; j < nevents; j += 1) {
994                     *(buffer)=0;
995                     buffer++;
996                 }
997             }
998             break;
999         case Port::E_Audio:
1000             switch(m_StreamProcessorManager.getAudioDataType()) {
1001             case StreamProcessorManager::eADT_Int24:
1002                 {
1003                     quadlet_t *buffer=(quadlet_t *)(p->getBufferAddress());
1004                     assert(nevents + offset <= p->getBufferSize());
1005                     buffer+=offset;
1006    
1007                     for(j = 0; j < nevents; j += 1) {
1008                         *(buffer)=0;
1009                         buffer++;
1010                     }
1011                 }
1012                 break;
1013             case StreamProcessorManager::eADT_Float:
1014                 {
1015                     float *buffer=(float *)(p->getBufferAddress());
1016                     assert(nevents + offset <= p->getBufferSize());
1017                     buffer+=offset;
1018    
1019                     for(j = 0; j < nevents; j += 1) {
1020                         *buffer = 0.0;
1021                         buffer++;
1022                     }
1023                 }
1024                 break;
1025             }
1026             break;
1027     }
1028     return 0;
1029 }
1030
1031 /***********************************************
1032  * State related API                           *
1033  ***********************************************/
1034 bool StreamProcessor::init()
1035 {
1036     debugOutput( DEBUG_LEVEL_VERY_VERBOSE, "init...\n");
1037
1038     if (sem_init(&m_signal_semaphore, 0, 0) == -1) {
1039         debugError("Could not init signal semaphore");
1040         return false;
1041     }
1042
1043     if(!m_IsoHandlerManager.registerStream(this)) {
1044         debugOutput(DEBUG_LEVEL_VERBOSE,"Could not register stream processor with the Iso manager\n");
1045         return false;
1046     }
1047     if(!m_StreamProcessorManager.registerProcessor(this)) {
1048         debugOutput(DEBUG_LEVEL_VERBOSE,"Could not register stream processor with the SP manager\n");
1049         return false;
1050     }
1051
1052     // initialization can be done without requesting it
1053     // from the packet loop
1054     m_next_state = ePS_Created;
1055     return true;
1056 }
1057
1058 bool StreamProcessor::prepare()
1059 {
1060     debugOutput( DEBUG_LEVEL_VERBOSE, "Prepare SP (%p)...\n", this);
1061
1062     // make the scratch buffer one period of frames long
1063     m_scratch_buffer_size_bytes = m_StreamProcessorManager.getPeriodSize() * getEventsPerFrame() * getEventSize();
1064     debugOutput( DEBUG_LEVEL_VERBOSE, " Allocate scratch buffer of %d quadlets\n");
1065     if(m_scratch_buffer) delete[] m_scratch_buffer;
1066     m_scratch_buffer = new byte_t[m_scratch_buffer_size_bytes];
1067     if(m_scratch_buffer == NULL) {
1068         debugFatal("Could not allocate scratch buffer\n");
1069         return false;
1070     }
1071
1072     // set the parameters of ports we can:
1073     // we want the audio ports to be period buffered,
1074     // and the midi ports to be packet buffered
1075     for ( PortVectorIterator it = m_Ports.begin();
1076         it != m_Ports.end();
1077         ++it )
1078     {
1079         debugOutput(DEBUG_LEVEL_VERBOSE, "Setting up port %s\n",(*it)->getName().c_str());
1080         if(!(*it)->setBufferSize(m_StreamProcessorManager.getPeriodSize())) {
1081             debugFatal("Could not set buffer size to %d\n",m_StreamProcessorManager.getPeriodSize());
1082             return false;
1083         }
1084     }
1085     // the API specific settings of the ports should already be set,
1086     // as this is called from the processorManager->prepare()
1087     // so we can init the ports
1088     if(!PortManager::initPorts()) {
1089         debugFatal("Could not initialize ports\n");
1090         return false;
1091     }
1092
1093     if (!prepareChild()) {
1094         debugFatal("Could not prepare child\n");
1095         return false;
1096     }
1097
1098     debugOutput( DEBUG_LEVEL_VERBOSE, "Prepared for:\n");
1099     debugOutput( DEBUG_LEVEL_VERBOSE, " Samplerate: %d\n",
1100              m_StreamProcessorManager.getNominalRate());
1101     debugOutput( DEBUG_LEVEL_VERBOSE, " PeriodSize: %d, NbBuffers: %d\n",
1102              m_StreamProcessorManager.getPeriodSize(), m_StreamProcessorManager.getNbBuffers());
1103     debugOutput( DEBUG_LEVEL_VERBOSE, " Port: %d, Channel: %d\n",
1104              m_1394service.getPort(), m_channel);
1105
1106     // initialization can be done without requesting it
1107     // from the packet loop
1108     m_next_state = ePS_Stopped;
1109     return updateState();
1110 }
1111
1112 bool
1113 StreamProcessor::scheduleStateTransition(enum eProcessorState state, uint64_t time_instant)
1114 {
1115     // first set the time, since in the packet loop we first check m_state == m_next_state before
1116     // using the time
1117     m_cycle_to_switch_state = TICKS_TO_CYCLES(time_instant);
1118     m_next_state = state;
1119     return true;
1120 }
1121
1122 bool
1123 StreamProcessor::waitForState(enum eProcessorState state, unsigned int timeout_ms)
1124 {
1125     debugOutput(DEBUG_LEVEL_VERBOSE, "Waiting for state %s\n", ePSToString(state));
1126     int cnt = timeout_ms;
1127     while (m_state != state && cnt) {
1128         SleepRelativeUsec(1000);
1129         cnt--;
1130     }
1131     if(cnt==0) {
1132         debugOutput(DEBUG_LEVEL_VERBOSE, " Timeout\n");
1133         return false;
1134     }
1135     return true;
1136 }
1137
1138 bool StreamProcessor::scheduleStartDryRunning(int64_t t) {
1139     uint64_t tx;
1140     if (t < 0) {
1141         tx = addTicks(m_1394service.getCycleTimerTicks(), 200 * TICKS_PER_CYCLE);
1142     } else {
1143         tx = t;
1144     }
1145     uint64_t start_handler_ticks = substractTicks(tx, 100 * TICKS_PER_CYCLE);
1146
1147     debugOutput(DEBUG_LEVEL_VERBOSE,"for %s SP (%p)\n", ePTToString(getType()), this);
1148     uint64_t now = m_1394service.getCycleTimerTicks();
1149     debugOutput(DEBUG_LEVEL_VERBOSE,"  Now                   : %011llu (%03us %04uc %04ut)\n",
1150                           now,
1151                           (unsigned int)TICKS_TO_SECS(now),
1152                           (unsigned int)TICKS_TO_CYCLES(now),
1153                           (unsigned int)TICKS_TO_OFFSET(now));
1154     debugOutput(DEBUG_LEVEL_VERBOSE,"  Start at              : %011llu (%03us %04uc %04ut)\n",
1155                           tx,
1156                           (unsigned int)TICKS_TO_SECS(tx),
1157                           (unsigned int)TICKS_TO_CYCLES(tx),
1158                           (unsigned int)TICKS_TO_OFFSET(tx));
1159     if (m_state == ePS_Stopped) {
1160         if(!m_IsoHandlerManager.startHandlerForStream(
1161                                         this, TICKS_TO_CYCLES(start_handler_ticks))) {
1162             debugError("Could not start handler for SP %p\n", this);
1163             return false;
1164         }
1165         return scheduleStateTransition(ePS_WaitingForStream, tx);
1166     } else if (m_state == ePS_Running) {
1167         return scheduleStateTransition(ePS_WaitingForStreamDisable, tx);
1168     } else {
1169         debugError("Cannot switch to ePS_DryRunning from %s\n", ePSToString(m_state));
1170         return false;
1171     }
1172 }
1173
1174 bool StreamProcessor::scheduleStartRunning(int64_t t) {
1175     uint64_t tx;
1176     if (t < 0) {
1177         tx = addTicks(m_1394service.getCycleTimerTicks(), 200 * TICKS_PER_CYCLE);
1178     } else {
1179         tx = t;
1180     }
1181     debugOutput(DEBUG_LEVEL_VERBOSE,"for %s SP (%p)\n", ePTToString(getType()), this);
1182     uint64_t now = m_1394service.getCycleTimerTicks();
1183     debugOutput(DEBUG_LEVEL_VERBOSE,"  Now                   : %011llu (%03us %04uc %04ut)\n",
1184                           now,
1185                           (unsigned int)TICKS_TO_SECS(now),
1186                           (unsigned int)TICKS_TO_CYCLES(now),
1187                           (unsigned int)TICKS_TO_OFFSET(now));
1188     debugOutput(DEBUG_LEVEL_VERBOSE,"  Start at              : %011llu (%03us %04uc %04ut)\n",
1189                           tx,
1190                           (unsigned int)TICKS_TO_SECS(tx),
1191                           (unsigned int)TICKS_TO_CYCLES(tx),
1192                           (unsigned int)TICKS_TO_OFFSET(tx));
1193     return scheduleStateTransition(ePS_WaitingForStreamEnable, tx);
1194 }
1195
1196 bool StreamProcessor::scheduleStopDryRunning(int64_t t) {
1197     uint64_t tx;
1198     if (t < 0) {
1199         tx = addTicks(m_1394service.getCycleTimerTicks(), 200 * TICKS_PER_CYCLE);
1200     } else {
1201         tx = t;
1202     }
1203     debugOutput(DEBUG_LEVEL_VERBOSE,"for %s SP (%p)\n", ePTToString(getType()), this);
1204     uint64_t now = m_1394service.getCycleTimerTicks();
1205     debugOutput(DEBUG_LEVEL_VERBOSE,"  Now                   : %011llu (%03us %04uc %04ut)\n",
1206                           now,
1207                           (unsigned int)TICKS_TO_SECS(now),
1208                           (unsigned int)TICKS_TO_CYCLES(now),
1209                           (unsigned int)TICKS_TO_OFFSET(now));
1210     debugOutput(DEBUG_LEVEL_VERBOSE,"  Stop at               : %011llu (%03us %04uc %04ut)\n",
1211                           tx,
1212                           (unsigned int)TICKS_TO_SECS(tx),
1213                           (unsigned int)TICKS_TO_CYCLES(tx),
1214                           (unsigned int)TICKS_TO_OFFSET(tx));
1215
1216     return scheduleStateTransition(ePS_Stopped, tx);
1217 }
1218
1219 bool StreamProcessor::scheduleStopRunning(int64_t t) {
1220     uint64_t tx;
1221     if (t < 0) {
1222         tx = addTicks(m_1394service.getCycleTimerTicks(), 200 * TICKS_PER_CYCLE);
1223     } else {
1224         tx = t;
1225     }
1226     debugOutput(DEBUG_LEVEL_VERBOSE,"for %s SP (%p)\n", ePTToString(getType()), this);
1227     uint64_t now = m_1394service.getCycleTimerTicks();
1228     debugOutput(DEBUG_LEVEL_VERBOSE,"  Now                   : %011llu (%03us %04uc %04ut)\n",
1229                           now,
1230                           (unsigned int)TICKS_TO_SECS(now),
1231                           (unsigned int)TICKS_TO_CYCLES(now),
1232                           (unsigned int)TICKS_TO_OFFSET(now));
1233     debugOutput(DEBUG_LEVEL_VERBOSE,"  Stop at               : %011llu (%03us %04uc %04ut)\n",
1234                           tx,
1235                           (unsigned int)TICKS_TO_SECS(tx),
1236                           (unsigned int)TICKS_TO_CYCLES(tx),
1237                           (unsigned int)TICKS_TO_OFFSET(tx));
1238     return scheduleStateTransition(ePS_WaitingForStreamDisable, tx);
1239 }
1240
1241 bool StreamProcessor::startDryRunning(int64_t t) {
1242     if(!scheduleStartDryRunning(t)) {
1243         debugError("Could not schedule transition\n");
1244         return false;
1245     }
1246     if(!waitForState(ePS_DryRunning, 2000)) {
1247         debugError(" Timeout while waiting for %s\n", ePSToString(ePS_DryRunning));
1248         return false;
1249     }
1250     return true;
1251 }
1252
1253 bool StreamProcessor::startRunning(int64_t t) {
1254     if(!scheduleStartRunning(t)) {
1255         debugError("Could not schedule transition\n");
1256         return false;
1257     }
1258     if(!waitForState(ePS_Running, 2000)) {
1259         debugError(" Timeout while waiting for %s\n", ePSToString(ePS_Running));
1260         return false;
1261     }
1262     return true;
1263 }
1264
1265 bool StreamProcessor::stopDryRunning(int64_t t) {
1266     if(!scheduleStopDryRunning(t)) {
1267         debugError("Could not schedule transition\n");
1268         return false;
1269     }
1270     if(!waitForState(ePS_Stopped, 2000)) {
1271         debugError(" Timeout while waiting for %s\n", ePSToString(ePS_Stopped));
1272         return false;
1273     }
1274     return true;
1275 }
1276
1277 bool StreamProcessor::stopRunning(int64_t t) {
1278     if(!scheduleStopRunning(t)) {
1279         debugError("Could not schedule transition\n");
1280         return false;
1281     }
1282     if(!waitForState(ePS_DryRunning, 2000)) {
1283         debugError(" Timeout while waiting for %s\n", ePSToString(ePS_DryRunning));
1284         return false;
1285     }
1286     return true;
1287 }
1288
1289
1290 // internal state API
1291
1292 /**
1293  * @brief Enter the ePS_Stopped state
1294  * @return true if successful, false if not
1295  *
1296  * @pre none
1297  *
1298  * @post the buffer and the isostream are ready for use.
1299  * @post all dynamic structures have been allocated successfully
1300  * @post the buffer is transparent and empty, and all parameters are set
1301  *       to the correct initial/nominal values.
1302  *
1303  */
1304 bool
1305 StreamProcessor::doStop()
1306 {
1307     float ticks_per_frame;
1308     unsigned int ringbuffer_size_frames = (m_StreamProcessorManager.getNbBuffers() + 1) * m_StreamProcessorManager.getPeriodSize();
1309
1310     debugOutput(DEBUG_LEVEL_VERBOSE, "Enter from state: %s\n", ePSToString(m_state));
1311     bool result = true;
1312
1313     switch(m_state) {
1314         case ePS_Created:
1315             assert(m_data_buffer);
1316
1317             // prepare the framerate estimate
1318             ticks_per_frame = (TICKS_PER_SECOND*1.0) / ((float)m_StreamProcessorManager.getNominalRate());
1319             m_ticks_per_frame = ticks_per_frame;
1320             debugOutput(DEBUG_LEVEL_VERBOSE,"Initializing remote ticks/frame to %f\n", ticks_per_frame);
1321
1322             // initialize internal buffer
1323             result &= m_data_buffer->setBufferSize(ringbuffer_size_frames);
1324
1325             result &= m_data_buffer->setEventSize( getEventSize() );
1326             result &= m_data_buffer->setEventsPerFrame( getEventsPerFrame() );
1327             if(getType() == ePT_Receive) {
1328                 result &= m_data_buffer->setUpdatePeriod( getNominalFramesPerPacket() );
1329             } else {
1330                 result &= m_data_buffer->setUpdatePeriod( m_StreamProcessorManager.getPeriodSize() );
1331             }
1332             result &= m_data_buffer->setNominalRate(ticks_per_frame);
1333             result &= m_data_buffer->setWrapValue(128L*TICKS_PER_SECOND);
1334             result &= m_data_buffer->prepare(); // FIXME: the name
1335
1336             break;
1337         case ePS_DryRunning:
1338             if(!m_IsoHandlerManager.stopHandlerForStream(this)) {
1339                 debugError("Could not stop handler for SP %p\n", this);
1340                 return false;
1341             }
1342             break;
1343         default:
1344             debugError("Entry from invalid state: %s\n", ePSToString(m_state));
1345             return false;
1346     }
1347
1348     result &= m_data_buffer->clearBuffer(); // FIXME: don't like the reset() name
1349     // make the buffer transparent
1350     m_data_buffer->setTransparent(true);
1351
1352     // reset all ports
1353     result &= PortManager::preparePorts();
1354
1355     m_state = ePS_Stopped;
1356     #ifdef DEBUG
1357     if (getDebugLevel() >= DEBUG_LEVEL_VERBOSE) {
1358         debugOutput(DEBUG_LEVEL_VERBOSE, "State switch complete, dumping SP info...\n");
1359         dumpInfo();
1360     }
1361     #endif
1362     return result;
1363 }
1364
1365 /**
1366  * @brief Enter the ePS_WaitingForStream state
1367  * @return true if successful, false if not
1368  *
1369  * @pre all dynamic data structures are allocated successfully
1370  *
1371  * @post
1372  *
1373  */
1374 bool
1375 StreamProcessor::doWaitForRunningStream()
1376 {
1377     debugOutput(DEBUG_LEVEL_VERBOSE, "Enter from state: %s\n", ePSToString(m_state));
1378     switch(m_state) {
1379         case ePS_Stopped:
1380             // we have to start waiting for an incoming stream
1381             // this basically means nothing, the state change will
1382             // be picked up by the packet iterator
1383             break;
1384         default:
1385             debugError("Entry from invalid state: %s\n", ePSToString(m_state));
1386             return false;
1387     }
1388     m_state = ePS_WaitingForStream;
1389     #ifdef DEBUG
1390     if (getDebugLevel() >= DEBUG_LEVEL_VERBOSE) {
1391         debugOutput(DEBUG_LEVEL_VERBOSE, "State switch complete, dumping SP info...\n");
1392         dumpInfo();
1393     }
1394     #endif
1395     return true;
1396 }
1397
1398 /**
1399  * @brief Enter the ePS_DryRunning state
1400  * @return true if successful, false if not
1401  *
1402  * @pre
1403  *
1404  * @post
1405  *
1406  */
1407 bool
1408 StreamProcessor::doDryRunning()
1409 {
1410     bool result = true;
1411     debugOutput(DEBUG_LEVEL_VERBOSE, "Enter from state: %s\n", ePSToString(m_state));
1412     switch(m_state) {
1413         case ePS_WaitingForStream:
1414             // a running stream has been detected
1415             debugOutput(DEBUG_LEVEL_VERBOSE, "StreamProcessor %p started dry-running at cycle %d\n", this, m_last_cycle);
1416             if (getType() == ePT_Receive) {
1417                 // this to ensure that there is no discontinuity when starting to
1418                 // update the DLL based upon the received packets
1419                 m_data_buffer->setBufferTailTimestamp(m_last_timestamp);
1420             } else {
1421                 // FIXME: PC=master mode will have to do something here I guess...
1422             }
1423             break;
1424         case ePS_WaitingForStreamEnable: // when xrunning at startup
1425             result &= m_data_buffer->clearBuffer();
1426             m_data_buffer->setTransparent(true);
1427             break;
1428         case ePS_WaitingForStreamDisable:
1429             result &= m_data_buffer->clearBuffer();
1430             m_data_buffer->setTransparent(true);
1431             break;
1432         default:
1433             debugError("Entry from invalid state: %s\n", ePSToString(m_state));
1434             return false;
1435     }
1436     m_state = ePS_DryRunning;
1437     #ifdef DEBUG
1438     if (getDebugLevel() >= DEBUG_LEVEL_VERBOSE) {
1439         debugOutput(DEBUG_LEVEL_VERBOSE, "State switch complete, dumping SP info...\n");
1440         dumpInfo();
1441     }
1442     #endif
1443     return result;
1444 }
1445
1446 /**
1447  * @brief Enter the ePS_WaitingForStreamEnable state
1448  * @return true if successful, false if not
1449  *
1450  * @pre
1451  *
1452  * @post
1453  *
1454  */
1455 bool
1456 StreamProcessor::doWaitForStreamEnable()
1457 {
1458     debugOutput(DEBUG_LEVEL_VERBOSE, "Enter from state: %s\n", ePSToString(m_state));
1459     unsigned int ringbuffer_size_frames;
1460     switch(m_state) {
1461         case ePS_DryRunning:
1462             // we have to start waiting for an incoming stream
1463             // this basically means nothing, the state change will
1464             // be picked up by the packet iterator
1465
1466             sem_init(&m_signal_semaphore, 0, 0);
1467             m_signal_period = m_StreamProcessorManager.getPeriodSize();
1468             m_signal_offset = 0; // FIXME: we have to ensure that everyone is ready
1469
1470             if(!m_data_buffer->clearBuffer()) {
1471                 debugError("Could not reset data buffer\n");
1472                 return false;
1473             }
1474             if (getType() == ePT_Transmit) {
1475                 ringbuffer_size_frames = m_StreamProcessorManager.getNbBuffers() * m_StreamProcessorManager.getPeriodSize();
1476                 debugOutput(DEBUG_LEVEL_VERBOSE, "Prefill transmit SP %p with %u frames\n", this, ringbuffer_size_frames);
1477                 // prefill the buffer
1478                 if(!transferSilence(ringbuffer_size_frames)) {
1479                     debugFatal("Could not prefill transmit stream\n");
1480                     return false;
1481                 }
1482                 if (m_data_buffer->getBufferFill() >= m_signal_period + m_signal_offset) {
1483                     POST_SEMAPHORE;
1484                 }
1485             }
1486
1487             break;
1488         default:
1489             debugError("Entry from invalid state: %s\n", ePSToString(m_state));
1490             return false;
1491     }
1492     m_state = ePS_WaitingForStreamEnable;
1493     #ifdef DEBUG
1494     if (getDebugLevel() >= DEBUG_LEVEL_VERBOSE) {
1495         debugOutput(DEBUG_LEVEL_VERBOSE, "State switch complete, dumping SP info...\n");
1496         dumpInfo();
1497     }
1498     #endif
1499     return true;
1500 }
1501
1502 /**
1503  * @brief Enter the ePS_Running state
1504  * @return true if successful, false if not
1505  *
1506  * @pre
1507  *
1508  * @post
1509  *
1510  */
1511 bool
1512 StreamProcessor::doRunning()
1513 {
1514     bool result = true;
1515     debugOutput(DEBUG_LEVEL_VERBOSE, "Enter from state: %s\n", ePSToString(m_state));
1516     switch(m_state) {
1517         case ePS_WaitingForStreamEnable:
1518             // a running stream has been detected
1519             debugOutput(DEBUG_LEVEL_VERBOSE, "StreamProcessor %p started running at cycle %d\n",
1520                                              this, m_last_cycle);
1521             m_in_xrun = false;
1522             m_data_buffer->setTransparent(false);
1523             break;
1524         default:
1525             debugError("Entry from invalid state: %s\n", ePSToString(m_state));
1526             return false;
1527     }
1528     m_state = ePS_Running;
1529     #ifdef DEBUG
1530     if (getDebugLevel() >= DEBUG_LEVEL_VERBOSE) {
1531         debugOutput(DEBUG_LEVEL_VERBOSE, "State switch complete, dumping SP info...\n");
1532         dumpInfo();
1533     }
1534     #endif
1535     return result;
1536 }
1537
1538 /**
1539  * @brief Enter the ePS_WaitingForStreamDisable state
1540  * @return true if successful, false if not
1541  *
1542  * @pre
1543  *
1544  * @post
1545  *
1546  */
1547 bool
1548 StreamProcessor::doWaitForStreamDisable()
1549 {
1550     debugOutput(DEBUG_LEVEL_VERBOSE, "Enter from state: %s\n", ePSToString(m_state));
1551     switch(m_state) {
1552         case ePS_Running:
1553             // the thread will do the transition
1554
1555             // we have to wake the iterator if it's asleep
1556             POST_SEMAPHORE;
1557             break;
1558         default:
1559             debugError("Entry from invalid state: %s\n", ePSToString(m_state));
1560             return false;
1561     }
1562     m_state = ePS_WaitingForStreamDisable;
1563     #ifdef DEBUG
1564     if (getDebugLevel() >= DEBUG_LEVEL_VERBOSE) {
1565         debugOutput(DEBUG_LEVEL_VERBOSE, "State switch complete, dumping SP info...\n");
1566         dumpInfo();
1567     }
1568     #endif
1569     return true;
1570 }
1571
1572 /**
1573  * @brief Updates the state machine and calls the necessary transition functions
1574  * @return true if successful, false if not
1575  */
1576 bool StreamProcessor::updateState() {
1577     bool result = false;
1578     // copy the current state locally since it could change value,
1579     // and that's something we don't want to happen inbetween tests
1580     // if m_next_state changes during this routine, we know for sure
1581     // that the previous state change was at least attempted correctly.
1582     enum eProcessorState next_state = m_next_state;
1583
1584     debugOutput(DEBUG_LEVEL_VERBOSE, "Do state transition: %s => %s\n",
1585         ePSToString(m_state), ePSToString(next_state));
1586
1587     if (m_state == next_state) {
1588         debugWarning("ignoring identity state update from/to %s\n", ePSToString(m_state) );
1589         return true;
1590     }
1591
1592     // after creation, only initialization is allowed
1593     if (m_state == ePS_Created) {
1594         if(next_state != ePS_Stopped) {
1595             goto updateState_exit_with_error;
1596         }
1597         // do init here
1598         result = doStop();
1599         if (result) return true;
1600         else goto updateState_exit_change_failed;
1601     }
1602
1603     // after initialization, only WaitingForRunningStream is allowed
1604     if (m_state == ePS_Stopped) {
1605         if(next_state != ePS_WaitingForStream) {
1606             goto updateState_exit_with_error;
1607         }
1608         result = doWaitForRunningStream();
1609         if (result) return true;
1610         else goto updateState_exit_change_failed;
1611     }
1612
1613     // after WaitingForStream, only ePS_DryRunning is allowed
1614     // this means that the stream started running
1615     if (m_state == ePS_WaitingForStream) {
1616         if(next_state != ePS_DryRunning) {
1617             goto updateState_exit_with_error;
1618         }
1619         result = doDryRunning();
1620         if (result) return true;
1621         else goto updateState_exit_change_failed;
1622     }
1623
1624     // from ePS_DryRunning we can go to:
1625     //   - ePS_Stopped if something went wrong during DryRunning
1626     //   - ePS_WaitingForStreamEnable if there is a requested to enable
1627     if (m_state == ePS_DryRunning) {
1628         if((next_state != ePS_Stopped) &&
1629            (next_state != ePS_WaitingForStreamEnable)) {
1630             goto updateState_exit_with_error;
1631         }
1632         if (next_state == ePS_Stopped) {
1633             result = doStop();
1634         } else {
1635             result = doWaitForStreamEnable();
1636         }
1637         if (result) return true;
1638         else goto updateState_exit_change_failed;
1639     }
1640
1641     // from ePS_WaitingForStreamEnable we can go to:
1642     //   - ePS_DryRunning if something went wrong while waiting
1643     //   - ePS_Running if the stream enabled correctly
1644     if (m_state == ePS_WaitingForStreamEnable) {
1645         if((next_state != ePS_DryRunning) &&
1646            (next_state != ePS_Running)) {
1647             goto updateState_exit_with_error;
1648         }
1649         if (next_state == ePS_Stopped) {
1650             result = doDryRunning();
1651         } else {
1652             result = doRunning();
1653         }
1654         if (result) return true;
1655         else goto updateState_exit_change_failed;
1656     }
1657
1658     // from ePS_Running we can only start waiting for a disabled stream
1659     if (m_state == ePS_Running) {
1660         if(next_state != ePS_WaitingForStreamDisable) {
1661             goto updateState_exit_with_error;
1662         }
1663         result = doWaitForStreamDisable();
1664         if (result) return true;
1665         else goto updateState_exit_change_failed;
1666     }
1667
1668     // from ePS_WaitingForStreamDisable we can go to DryRunning
1669     if (m_state == ePS_WaitingForStreamDisable) {
1670         if(next_state != ePS_DryRunning) {
1671             goto updateState_exit_with_error;
1672         }
1673         result = doDryRunning();
1674         if (result) return true;
1675         else goto updateState_exit_change_failed;
1676     }
1677
1678     // if we arrive here there is an error
1679 updateState_exit_with_error:
1680     debugError("Invalid state transition: %s => %s\n",
1681         ePSToString(m_state), ePSToString(next_state));
1682     return false;
1683 updateState_exit_change_failed:
1684     debugError("State transition failed: %s => %s\n",
1685         ePSToString(m_state), ePSToString(next_state));
1686     return false;
1687 }
1688
1689 /***********************************************
1690  * Helper routines                             *
1691  ***********************************************/
1692 bool
1693 StreamProcessor::transferSilence(unsigned int nframes)
1694 {
1695     bool retval;
1696     signed int fc;
1697     ffado_timestamp_t ts_tail_tmp;
1698
1699     // prepare a buffer of silence
1700     char *dummybuffer = (char *)calloc(getEventSize(), nframes * getEventsPerFrame());
1701     transmitSilenceBlock(dummybuffer, nframes, 0);
1702
1703     m_data_buffer->getBufferTailTimestamp(&ts_tail_tmp, &fc);
1704     if (fc != 0) {
1705         debugWarning("Prefilling a buffer that already contains %d frames\n", fc);
1706     }
1707
1708     // add the silence data to the ringbuffer
1709     if(m_data_buffer->preloadFrames(nframes, dummybuffer, true)) {
1710         retval = true;
1711     } else {
1712         debugWarning("Could not write to event buffer\n");
1713         retval = false;
1714     }
1715     free(dummybuffer);
1716     return retval;
1717 }
1718
1719 /**
1720  * @brief convert a eProcessorState to a string
1721  * @param s the state
1722  * @return a char * describing the state
1723  */
1724 const char *
1725 StreamProcessor::ePSToString(enum eProcessorState s) {
1726     switch (s) {
1727         case ePS_Invalid: return "ePS_Invalid";
1728         case ePS_Created: return "ePS_Created";
1729         case ePS_Stopped: return "ePS_Stopped";
1730         case ePS_WaitingForStream: return "ePS_WaitingForStream";
1731         case ePS_DryRunning: return "ePS_DryRunning";
1732         case ePS_WaitingForStreamEnable: return "ePS_WaitingForStreamEnable";
1733         case ePS_Running: return "ePS_Running";
1734         case ePS_WaitingForStreamDisable: return "ePS_WaitingForStreamDisable";
1735         default: return "error: unknown state";
1736     }
1737 }
1738
1739 /**
1740  * @brief convert a eProcessorType to a string
1741  * @param t the type
1742  * @return a char * describing the state
1743  */
1744 const char *
1745 StreamProcessor::ePTToString(enum eProcessorType t) {
1746     switch (t) {
1747         case ePT_Receive: return "Receive";
1748         case ePT_Transmit: return "Transmit";
1749         default: return "error: unknown type";
1750     }
1751 }
1752
1753 /***********************************************
1754  * Debug                                       *
1755  ***********************************************/
1756 void
1757 StreamProcessor::dumpInfo()
1758 {
1759     debugOutputShort( DEBUG_LEVEL_NORMAL, " StreamProcessor %p, %s:\n", this, ePTToString(m_processor_type));
1760     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Port, Channel  : %d, %d\n", m_1394service.getPort(), m_channel);
1761     uint64_t now = m_1394service.getCycleTimerTicks();
1762     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Now                   : %011llu (%03us %04uc %04ut)\n",
1763                         now,
1764                         (unsigned int)TICKS_TO_SECS(now),
1765                         (unsigned int)TICKS_TO_CYCLES(now),
1766                         (unsigned int)TICKS_TO_OFFSET(now));
1767     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Xrun?                 : %s\n", (m_in_xrun ? "True":"False"));
1768     if (m_state == m_next_state) {
1769         debugOutputShort( DEBUG_LEVEL_NORMAL, "  State                 : %s\n",
1770                                             ePSToString(m_state));
1771     } else {
1772         debugOutputShort( DEBUG_LEVEL_NORMAL, "  State                 : %s (Next: %s)\n",
1773                                               ePSToString(m_state), ePSToString(m_next_state));
1774         debugOutputShort( DEBUG_LEVEL_NORMAL, "    transition at       : %u\n", m_cycle_to_switch_state);
1775     }
1776     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Buffer                : %p\n", m_data_buffer);
1777     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Framerate             : Nominal: %u, Sync: %f, Buffer %f\n",
1778                                           m_StreamProcessorManager.getNominalRate(),
1779                                           24576000.0/m_StreamProcessorManager.getSyncSource().m_data_buffer->getRate(),
1780                                           24576000.0/m_data_buffer->getRate());
1781     float d = getSyncDelay();
1782     debugOutputShort(DEBUG_LEVEL_NORMAL, "  Sync delay             : %f ticks (%f frames, %f cy)\n",
1783                                          d, d/getTicksPerFrame(),
1784                                          d/((float)TICKS_PER_CYCLE));
1785     m_data_buffer->dumpInfo();
1786 }
1787
1788 void
1789 StreamProcessor::setVerboseLevel(int l) {
1790     setDebugLevel(l);
1791     PortManager::setVerboseLevel(l);
1792     m_data_buffer->setVerboseLevel(l);
1793 }
1794
1795 } // end of namespace
Note: See TracBrowser for help on using the browser.