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

Revision 811, 66.6 kB (checked in by ppalmers, 16 years ago)

fixes for introduced bugs

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     sem_destroy(&m_signal_semaphore);
91
92     // FIXME: how do we ensure that nobody is using us?
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                 }
477             }
478             return RAW1394_ISO_OK;
479         } else {
480             debugError("Invalid response\n");
481             POST_SEMAPHORE;
482             return RAW1394_ISO_ERROR;
483         }
484     } else if(result == eCRV_Invalid) {
485         // apparently we don't have to do anything when the packets are not valid
486         return RAW1394_ISO_OK;
487     } else {
488         debugError("Invalid response\n");
489         POST_SEMAPHORE;
490         return RAW1394_ISO_ERROR;
491     }
492     debugError("reached the unreachable\n");
493     POST_SEMAPHORE;
494     return RAW1394_ISO_ERROR;
495 }
496
497 enum raw1394_iso_disposition
498 StreamProcessor::getPacket(unsigned char *data, unsigned int *length,
499                            unsigned char *tag, unsigned char *sy,
500                            int cycle, unsigned int dropped, unsigned int max_length) {
501     if (cycle<0) {
502         *tag = 0;
503         *sy = 0;
504         *length = 0;
505         return RAW1394_ISO_OK;
506     }
507
508     unsigned int ctr;
509     int now_cycles;
510     int cycle_diff;
511
512     if(m_last_cycle == -1) {
513         debugOutput(DEBUG_LEVEL_VERBOSE, "Handler for %s SP %p is alive (cycle = %d)\n", getTypeString(), this, cycle);
514     }
515
516     int dropped_cycles = 0;
517     if (m_last_cycle != cycle && m_last_cycle != -1) {
518         dropped_cycles = diffCycles(cycle, m_last_cycle) - 1;
519         if (dropped_cycles < 0) {
520             debugWarning("(%p) dropped < 1 (%d), cycle: %d, last_cycle: %d, dropped: %d\n",
521                          this, dropped_cycles, cycle, m_last_cycle, dropped);
522         }
523         if (dropped_cycles > 0) {
524             debugWarning("(%p) dropped %d packets on cycle %u (last_cycle=%u, dropped=%d)\n", this, dropped_cycles, cycle, m_last_cycle, dropped);
525             m_dropped += dropped_cycles;
526             // HACK: this should not be necessary, since the header generation functions should trigger the xrun.
527             //       but apparently there are some issues with the 1394 stack
528             m_in_xrun = true;
529             if(m_state == ePS_Running) {
530                 debugShowBackLogLines(200);
531                 debugWarning("dropped packets xrun\n");
532                 debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to WaitingForStreamDisable due to dropped packets xrun\n");
533                 m_next_state = ePS_WaitingForStreamDisable;
534                 // execute the requested change
535                 if (!updateState()) { // we are allowed to change the state directly
536                     debugError("Could not update state!\n");
537                     return RAW1394_ISO_ERROR;
538                 }
539                 goto send_empty_packet;
540             }
541         }
542     }
543     if (cycle >= 0) {
544         m_last_cycle = cycle;
545     }
546
547     // bypass based upon state
548     if (m_state == ePS_Invalid) {
549         debugError("Should not have state %s\n", ePSToString(m_state) );
550         return RAW1394_ISO_ERROR;
551     }
552     if (m_state == ePS_Created) {
553         *tag = 0;
554         *sy = 0;
555         *length = 0;
556         return RAW1394_ISO_DEFER;
557     }
558
559     // normal processing
560     // note that we can't use getCycleTimer directly here,
561     // because packets are queued in advance. This means that
562     // we the packet we are constructing will be sent out
563     // on 'cycle', not 'now'.
564     ctr = m_1394service.getCycleTimer();
565     now_cycles = (int)CYCLE_TIMER_GET_CYCLES(ctr);
566
567     // the difference between the cycle this
568     // packet is intended for and 'now'
569     cycle_diff = diffCycles(cycle, now_cycles);
570
571     if(cycle_diff < 0 && (m_state == ePS_Running || m_state == ePS_DryRunning)) {
572         debugWarning("Requesting packet for cycle %04d which is in the past (now=%04dcy)\n",
573             cycle, now_cycles);
574         if(m_state == ePS_Running) {
575             debugShowBackLogLines(200);
576 //             flushDebugOutput();
577 //             assert(0);
578             debugWarning("generatePacketData xrun\n");
579             m_in_xrun = true;
580             debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to WaitingForStreamDisable due to data xrun\n");
581             m_next_state = ePS_WaitingForStreamDisable;
582             // execute the requested change
583             if (!updateState()) { // we are allowed to change the state directly
584                 debugError("Could not update state!\n");
585                 return RAW1394_ISO_ERROR;
586             }
587             goto send_empty_packet;
588         }
589     }
590
591     // store the previous timestamp
592     m_last_timestamp2 = m_last_timestamp;
593
594     // NOTE: synchronized switching is restricted to a 0.5 sec span (4000 cycles)
595     //       it happens on the first 'good' cycle for the wait condition
596     //       or on the first received cycle that is received afterwards (might be a problem)
597
598     // check whether we are waiting for a stream to be disabled
599     if(m_state == ePS_WaitingForStreamDisable) {
600         // we then check whether we have to switch on this cycle
601         if (diffCycles(cycle, m_cycle_to_switch_state) >= 0) {
602             debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to DryRunning\n");
603             m_next_state = ePS_DryRunning;
604             if (!updateState()) { // we are allowed to change the state directly
605                 debugError("Could not update state!\n");
606                 return RAW1394_ISO_ERROR;
607             }
608         } else {
609             // not time to disable yet
610         }
611     }
612     // check whether we are waiting for a stream to be enabled
613     else if(m_state == ePS_WaitingForStreamEnable) {
614         // we then check whether we have to switch on this cycle
615         if (diffCycles(cycle, m_cycle_to_switch_state) >= 0) {
616             debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to Running\n");
617             m_next_state = ePS_Running;
618             if (!updateState()) { // we are allowed to change the state directly
619                 debugError("Could not update state!\n");
620                 return RAW1394_ISO_ERROR;
621             }
622         } else {
623             // not time to enable yet
624         }
625         // we are dryRunning hence data should be processed in any case
626     }
627     // check whether we are waiting for a stream to startup
628     else if(m_state == ePS_WaitingForStream) {
629         // as long as the cycle parameter is not in sync with
630         // the current time, the stream is considered not
631         // to be 'running'
632         // we then check whether we have to switch on this cycle
633         if ((cycle_diff >= 0) && (diffCycles(cycle, m_cycle_to_switch_state) >= 0)) {
634             debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to WaitingForStream to DryRunning\n");
635             // hence go to the dryRunning state
636             m_next_state = ePS_DryRunning;
637             if (!updateState()) { // we are allowed to change the state directly
638                 debugError("Could not update state!\n");
639                 return RAW1394_ISO_ERROR;
640             }
641         } else {
642             // not time (yet) to switch state
643         }
644     }
645     else if(m_state == ePS_Running) {
646         // check the packet header
647         enum eChildReturnValue result = generatePacketHeader(data, length, tag, sy, cycle, dropped_cycles, max_length);
648         if (result == eCRV_Packet || result == eCRV_Defer) {
649             debugOutput(DEBUG_LEVEL_VERY_VERBOSE, "XMIT: CY=%04u TS=%011llu\n",
650                     cycle, m_last_timestamp);
651             // update some accounting
652             m_last_good_cycle = cycle;
653             m_last_dropped = dropped_cycles;
654
655             // check whether a state change has been requested
656             // note that only the wait state changes are synchronized with the cycles
657             if(m_state != m_next_state) {
658                 debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state from %s to %s\n",
659                                                 ePSToString(m_state), ePSToString(m_next_state));
660                 // execute the requested change
661                 if (!updateState()) { // we are allowed to change the state directly
662                     debugError("Could not update state!\n");
663                     return RAW1394_ISO_ERROR;
664                 }
665             }
666
667             enum eChildReturnValue result2 = generatePacketData(data, length, tag, sy, cycle, dropped_cycles, max_length);
668             // if an xrun occured, switch to the dryRunning state and
669             // allow for the xrun to be picked up
670             if (result2 == eCRV_XRun) {
671                 debugWarning("generatePacketData xrun\n");
672                 m_in_xrun = true;
673                 debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to WaitingForStreamDisable due to data xrun\n");
674                 m_cycle_to_switch_state = cycle+1; // switch in the next cycle
675                 m_next_state = ePS_WaitingForStreamDisable;
676                 // execute the requested change
677                 if (!updateState()) { // we are allowed to change the state directly
678                     debugError("Could not update state!\n");
679                     return RAW1394_ISO_ERROR;
680                 }
681                 goto send_empty_packet;
682             }
683             // skip queueing packets if we detect that there are not enough frames
684             // available
685             if(result2 == eCRV_Defer || result == eCRV_Defer)
686                 return RAW1394_ISO_DEFER;
687             else
688                 return RAW1394_ISO_OK;
689         } else if (result == eCRV_XRun) { // pick up the possible xruns
690             debugWarning("generatePacketHeader xrun\n");
691             m_in_xrun = true;
692             debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to WaitingForStreamDisable due to header xrun\n");
693             m_next_state = ePS_WaitingForStreamDisable;
694             // execute the requested change
695             if (!updateState()) { // we are allowed to change the state directly
696                 debugError("Could not update state!\n");
697                 return RAW1394_ISO_ERROR;
698             }
699         } else if (result == eCRV_EmptyPacket) {
700             if(m_state != m_next_state) {
701                 debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state from %s to %s\n",
702                                                 ePSToString(m_state), ePSToString(m_next_state));
703                 // execute the requested change
704                 if (!updateState()) { // we are allowed to change the state directly
705                     debugError("Could not update state!\n");
706                     return RAW1394_ISO_ERROR;
707                 }
708             }
709             goto send_empty_packet;
710         } else if (result == eCRV_Again) {
711             debugOutput(DEBUG_LEVEL_VERY_VERBOSE, "have to retry cycle %d\n", cycle);
712             if(m_state != m_next_state) {
713                 debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state from %s to %s\n",
714                                                 ePSToString(m_state), ePSToString(m_next_state));
715                 // execute the requested change
716                 if (!updateState()) { // we are allowed to change the state directly
717                     debugError("Could not update state!\n");
718                     return RAW1394_ISO_ERROR;
719                 }
720             }
721             usleep(125); // only when using thread-per-handler
722             return RAW1394_ISO_AGAIN;
723 //             generateSilentPacketHeader(data, length, tag, sy, cycle, dropped_cycles, max_length);
724 //             generateSilentPacketData(data, length, tag, sy, cycle, dropped_cycles, max_length);
725 //             return RAW1394_ISO_DEFER;
726         } else {
727             debugError("Invalid return value: %d\n", result);
728             return RAW1394_ISO_ERROR;
729         }
730     }
731     // we are not running, so send an empty packet
732     // we should generate a valid packet any time
733 send_empty_packet:
734     // note that only the wait state changes are synchronized with the cycles
735     if(m_state != m_next_state) {
736         debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state from %s to %s\n",
737                                         ePSToString(m_state), ePSToString(m_next_state));
738         // execute the requested change
739         if (!updateState()) { // we are allowed to change the state directly
740             debugError("Could not update state!\n");
741             return RAW1394_ISO_ERROR;
742         }
743     }
744
745     debugOutput(DEBUG_LEVEL_VERY_VERBOSE, "XMIT EMPTY: CY=%04u\n", cycle);
746     generateSilentPacketHeader(data, length, tag, sy, cycle, dropped_cycles, max_length);
747     generateSilentPacketData(data, length, tag, sy, cycle, dropped_cycles, max_length);
748     return RAW1394_ISO_OK;
749 }
750
751
752 // Frame Transfer API
753 /**
754  * Transfer a block of frames from the event buffer to the port buffers
755  * @param nbframes number of frames to transfer
756  * @param ts the timestamp that the LAST frame in the block should have
757  * @return
758  */
759 bool StreamProcessor::getFrames(unsigned int nbframes, int64_t ts) {
760     debugOutput( DEBUG_LEVEL_VERY_VERBOSE, "%p.getFrames(%d, %11llu)", nbframes, ts);
761     assert( getType() == ePT_Receive );
762     if(isDryRunning()) return getFramesDry(nbframes, ts);
763     else return getFramesWet(nbframes, ts);
764 }
765
766 bool StreamProcessor::getFramesWet(unsigned int nbframes, int64_t ts) {
767 // FIXME: this should be done somewhere else
768 #ifdef DEBUG
769     uint64_t ts_expected;
770     signed int fc;
771     int32_t lag_ticks;
772     float lag_frames;
773
774     // in order to sync up multiple received streams, we should
775     // use the ts parameter. It specifies the time of the block's
776     // last sample.
777     float srate = m_StreamProcessorManager.getSyncSource().getTicksPerFrame();
778     assert(srate != 0.0);
779     int64_t this_block_length_in_ticks = (int64_t)(((float)nbframes) * srate);
780
781     ffado_timestamp_t ts_head_tmp;
782     m_data_buffer->getBufferHeadTimestamp(&ts_head_tmp, &fc);
783     ts_expected = addTicks((uint64_t)ts_head_tmp, this_block_length_in_ticks);
784
785     lag_ticks = diffTicks(ts, ts_expected);
786     lag_frames = (((float)lag_ticks) / srate);
787     debugOutput( DEBUG_LEVEL_VERY_VERBOSE, "stream (%p): drifts %6d ticks = %10.5f frames (rate=%10.5f), %lld, %llu, %d\n",
788                  this, lag_ticks, lag_frames, srate, ts, ts_expected, fc);
789     if (lag_frames >= 1.0) {
790         // the stream lags
791         debugWarning( "stream (%p): lags  with %6d ticks = %10.5f frames (rate=%10.5f), %lld, %llu, %d\n",
792                       this, lag_ticks, lag_frames, srate, ts, ts_expected, fc);
793     } else if (lag_frames <= -1.0) {
794         // the stream leads
795         debugWarning( "stream (%p): leads with %6d ticks = %10.5f frames (rate=%10.5f), %lld, %llu, %d\n",
796                       this, lag_ticks, lag_frames, srate, ts, ts_expected, fc);
797     }
798 #endif
799     // ask the buffer to process nbframes of frames
800     // using it's registered client's processReadBlock(),
801     // which should be ours
802     m_data_buffer->blockProcessReadFrames(nbframes);
803     return true;
804 }
805
806 bool StreamProcessor::getFramesDry(unsigned int nbframes, int64_t ts)
807 {
808     debugOutput( DEBUG_LEVEL_VERY_VERBOSE, "stream (%p): dry run %d frames (@ ts=%lld)\n",
809                  this, nbframes, ts);
810     // dry run on this side means that we put silence in all enabled ports
811     // since there is do data put into the ringbuffer in the dry-running state
812     return provideSilenceBlock(nbframes, 0);
813 }
814
815 bool
816 StreamProcessor::dropFrames(unsigned int nbframes, int64_t ts)
817 {
818     debugOutput(DEBUG_LEVEL_VERY_VERBOSE, "StreamProcessor::dropFrames(%d, %lld)\n", nbframes, ts);
819     return m_data_buffer->dropFrames(nbframes);
820 }
821
822 bool StreamProcessor::putFrames(unsigned int nbframes, int64_t ts)
823 {
824     debugOutput( DEBUG_LEVEL_VERY_VERBOSE, "%p.putFrames(%d, %11llu)", nbframes, ts);
825     assert( getType() == ePT_Transmit );
826
827     if(isDryRunning()) return putFramesDry(nbframes, ts);
828     else return putFramesWet(nbframes, ts);
829 }
830
831 bool
832 StreamProcessor::putFramesWet(unsigned int nbframes, int64_t ts)
833 {
834     debugOutput(DEBUG_LEVEL_ULTRA_VERBOSE, "StreamProcessor::putFramesWet(%d, %llu)\n", nbframes, ts);
835     // transfer the data
836     m_data_buffer->blockProcessWriteFrames(nbframes, ts);
837     debugOutput(DEBUG_LEVEL_ULTRA_VERBOSE, " New timestamp: %llu\n", ts);
838
839     unsigned int bufferfill = m_data_buffer->getBufferFill();
840     if (bufferfill >= m_signal_period + m_signal_offset) {
841         debugOutput(DEBUG_LEVEL_VERBOSE, "(%p) sufficient frames in buffer (%d / %d), posting semaphore\n",
842                                          this, bufferfill, m_signal_period + m_signal_offset);
843         POST_SEMAPHORE;
844     } else {
845         debugOutput(DEBUG_LEVEL_VERBOSE, "(%p) insufficient frames in buffer (%d / %d), not posting semaphore\n",
846                                          this, bufferfill, m_signal_period + m_signal_offset);
847     }
848     return true; // FIXME: what about failure?
849 }
850
851 bool
852 StreamProcessor::putFramesDry(unsigned int nbframes, int64_t ts)
853 {
854     debugOutput(DEBUG_LEVEL_ULTRA_VERBOSE, "StreamProcessor::putFramesDry(%d, %llu)\n", nbframes, ts);
855     // do nothing
856     return true;
857 }
858
859 bool
860 StreamProcessor::putSilenceFrames(unsigned int nbframes, int64_t ts)
861 {
862     debugOutput(DEBUG_LEVEL_ULTRA_VERBOSE, "StreamProcessor::putSilenceFrames(%d, %llu)\n", nbframes, ts);
863
864     size_t bytes_per_frame = getEventSize() * getEventsPerFrame();
865     unsigned int scratch_buffer_size_frames = m_scratch_buffer_size_bytes / bytes_per_frame;
866
867     if (nbframes > scratch_buffer_size_frames) {
868         debugError("nframes (%u) > scratch_buffer_size_frames (%u)\n",
869                    nbframes, scratch_buffer_size_frames);
870     }
871
872     assert(m_scratch_buffer);
873     if(!transmitSilenceBlock((char *)m_scratch_buffer, nbframes, 0)) {
874         debugError("Could not prepare silent block\n");
875         return false;
876     }
877     if(!m_data_buffer->writeFrames(nbframes, (char *)m_scratch_buffer, ts)) {
878         debugError("Could not write silent block\n");
879         return false;
880     }
881
882     unsigned int bufferfill = m_data_buffer->getBufferFill();
883     if (bufferfill >= m_signal_period + m_signal_offset) {
884         debugOutput(DEBUG_LEVEL_VERBOSE, "(%p) sufficient frames in buffer (%d / %d), posting semaphore\n",
885                                          this, bufferfill, m_signal_period + m_signal_offset);
886         POST_SEMAPHORE;
887     } else {
888         debugOutput(DEBUG_LEVEL_VERBOSE, "(%p) insufficient frames in buffer (%d / %d), not posting semaphore\n",
889                                          this, bufferfill, m_signal_period + m_signal_offset);
890     }
891
892     return true;
893 }
894
895 bool
896 StreamProcessor::waitForSignal()
897 {
898     int result;
899     if(m_state == ePS_Running) {
900         result = sem_wait(&m_signal_semaphore);
901 #ifdef DEBUG
902         int tmp;
903         sem_getvalue(&m_signal_semaphore, &tmp);
904         debugOutput(DEBUG_LEVEL_VERBOSE, " sem_wait returns: %d, sem_value: %d\n", result, tmp);
905 #endif
906         return result == 0;
907     } else {
908         // when we're not running, we can always provide frames
909         debugOutput(DEBUG_LEVEL_VERBOSE, "Not running...\n");
910         return true;
911     }
912 }
913
914 bool
915 StreamProcessor::tryWaitForSignal()
916 {
917     if(m_state == ePS_Running) {
918         return sem_trywait(&m_signal_semaphore) == 0;
919     } else {
920         // when we're not running, we can always provide frames
921         debugOutput(DEBUG_LEVEL_VERY_VERBOSE, "Not running...\n");
922         return true;
923     }
924 }
925
926 bool
927 StreamProcessor::canProcessPackets()
928 {
929     if(m_state != ePS_Running) return true;
930     bool result;
931     int bufferfill;
932     if(getType() == ePT_Receive) {
933         bufferfill = m_data_buffer->getBufferSpace();
934     } else {
935         bufferfill = m_data_buffer->getBufferFill();
936     }
937     result = bufferfill > getNominalFramesPerPacket();
938     debugOutput(DEBUG_LEVEL_VERBOSE, "(%p, %s) for a bufferfill of %d, we return %d\n",
939                 this, ePTToString(getType()), bufferfill, result);
940     return result;
941 }
942
943 bool
944 StreamProcessor::shiftStream(int nbframes)
945 {
946     if(nbframes == 0) return true;
947     if(nbframes > 0) {
948         return m_data_buffer->dropFrames(nbframes);
949     } else {
950         bool result = true;
951         while(nbframes++) {
952             result &= m_data_buffer->writeDummyFrame();
953         }
954         return result;
955     }
956 }
957
958 /**
959  * @brief write silence events to the stream ringbuffers.
960  */
961 bool StreamProcessor::provideSilenceBlock(unsigned int nevents, unsigned int offset)
962 {
963     bool no_problem=true;
964     for ( PortVectorIterator it = m_Ports.begin();
965           it != m_Ports.end();
966           ++it ) {
967         if((*it)->isDisabled()) {continue;};
968
969         if(provideSilenceToPort((*it), offset, nevents)) {
970             debugWarning("Could not put silence into to port %s",(*it)->getName().c_str());
971             no_problem=false;
972         }
973     }
974     return no_problem;
975 }
976
977 int
978 StreamProcessor::provideSilenceToPort(Port *p, unsigned int offset, unsigned int nevents)
979 {
980     unsigned int j=0;
981     switch(p->getDataType()) {
982         default:
983             debugError("Invalid port type: %d\n", p->getDataType());
984             return -1;
985         case Port::E_Int24:
986         case Port::E_MidiEvent:
987         case Port::E_ControlEvent:
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_Float:
1000             {
1001                 float *buffer=(float *)(p->getBufferAddress());
1002                 assert(nevents + offset <= p->getBufferSize());
1003                 buffer+=offset;
1004
1005                 for(j = 0; j < nevents; j += 1) {
1006                     *buffer = 0.0;
1007                     buffer++;
1008                 }
1009             }
1010             break;
1011     }
1012     return 0;
1013 }
1014
1015 /***********************************************
1016  * State related API                           *
1017  ***********************************************/
1018 bool StreamProcessor::init()
1019 {
1020     debugOutput( DEBUG_LEVEL_VERY_VERBOSE, "init...\n");
1021
1022     if (sem_init(&m_signal_semaphore, 0, 0) == -1) {
1023         debugError("Could not init signal semaphore");
1024         return false;
1025     }
1026
1027     if(!m_IsoHandlerManager.registerStream(this)) {
1028         debugOutput(DEBUG_LEVEL_VERBOSE,"Could not register stream processor with the Iso manager\n");
1029         return false;
1030     }
1031     if(!m_StreamProcessorManager.registerProcessor(this)) {
1032         debugOutput(DEBUG_LEVEL_VERBOSE,"Could not register stream processor with the SP manager\n");
1033         return false;
1034     }
1035
1036     // initialization can be done without requesting it
1037     // from the packet loop
1038     m_next_state = ePS_Created;
1039     return true;
1040 }
1041
1042 bool StreamProcessor::prepare()
1043 {
1044     debugOutput( DEBUG_LEVEL_VERBOSE, "Prepare SP (%p)...\n", this);
1045
1046     // make the scratch buffer one period of frames long
1047     m_scratch_buffer_size_bytes = m_StreamProcessorManager.getPeriodSize() * getEventsPerFrame() * getEventSize();
1048     debugOutput( DEBUG_LEVEL_VERBOSE, " Allocate scratch buffer of %d quadlets\n");
1049     if(m_scratch_buffer) delete[] m_scratch_buffer;
1050     m_scratch_buffer = new byte_t[m_scratch_buffer_size_bytes];
1051     if(m_scratch_buffer == NULL) {
1052         debugFatal("Could not allocate scratch buffer\n");
1053         return false;
1054     }
1055
1056     if (!prepareChild()) {
1057         debugFatal("Could not prepare child\n");
1058         return false;
1059     }
1060
1061     debugOutput( DEBUG_LEVEL_VERBOSE, "Prepared for:\n");
1062     debugOutput( DEBUG_LEVEL_VERBOSE, " Samplerate: %d\n",
1063              m_StreamProcessorManager.getNominalRate());
1064     debugOutput( DEBUG_LEVEL_VERBOSE, " PeriodSize: %d, NbBuffers: %d\n",
1065              m_StreamProcessorManager.getPeriodSize(), m_StreamProcessorManager.getNbBuffers());
1066     debugOutput( DEBUG_LEVEL_VERBOSE, " Port: %d, Channel: %d\n",
1067              m_1394service.getPort(), m_channel);
1068
1069     // initialization can be done without requesting it
1070     // from the packet loop
1071     m_next_state = ePS_Stopped;
1072     return updateState();
1073 }
1074
1075 bool
1076 StreamProcessor::scheduleStateTransition(enum eProcessorState state, uint64_t time_instant)
1077 {
1078     // first set the time, since in the packet loop we first check m_state == m_next_state before
1079     // using the time
1080     m_cycle_to_switch_state = TICKS_TO_CYCLES(time_instant);
1081     m_next_state = state;
1082     return true;
1083 }
1084
1085 bool
1086 StreamProcessor::waitForState(enum eProcessorState state, unsigned int timeout_ms)
1087 {
1088     debugOutput(DEBUG_LEVEL_VERBOSE, "Waiting for state %s\n", ePSToString(state));
1089     int cnt = timeout_ms;
1090     while (m_state != state && cnt) {
1091         SleepRelativeUsec(1000);
1092         cnt--;
1093     }
1094     if(cnt==0) {
1095         debugOutput(DEBUG_LEVEL_VERBOSE, " Timeout\n");
1096         return false;
1097     }
1098     return true;
1099 }
1100
1101 bool StreamProcessor::scheduleStartDryRunning(int64_t t) {
1102     uint64_t tx;
1103     if (t < 0) {
1104         tx = addTicks(m_1394service.getCycleTimerTicks(), 200 * TICKS_PER_CYCLE);
1105     } else {
1106         tx = t;
1107     }
1108     uint64_t start_handler_ticks = substractTicks(tx, 100 * TICKS_PER_CYCLE);
1109
1110     debugOutput(DEBUG_LEVEL_VERBOSE,"for %s SP (%p)\n", ePTToString(getType()), this);
1111     uint64_t now = m_1394service.getCycleTimerTicks();
1112     debugOutput(DEBUG_LEVEL_VERBOSE,"  Now                   : %011llu (%03us %04uc %04ut)\n",
1113                           now,
1114                           (unsigned int)TICKS_TO_SECS(now),
1115                           (unsigned int)TICKS_TO_CYCLES(now),
1116                           (unsigned int)TICKS_TO_OFFSET(now));
1117     debugOutput(DEBUG_LEVEL_VERBOSE,"  Start at              : %011llu (%03us %04uc %04ut)\n",
1118                           tx,
1119                           (unsigned int)TICKS_TO_SECS(tx),
1120                           (unsigned int)TICKS_TO_CYCLES(tx),
1121                           (unsigned int)TICKS_TO_OFFSET(tx));
1122     if (m_state == ePS_Stopped) {
1123         if(!m_IsoHandlerManager.startHandlerForStream(
1124                                         this, TICKS_TO_CYCLES(start_handler_ticks))) {
1125             debugError("Could not start handler for SP %p\n", this);
1126             return false;
1127         }
1128         return scheduleStateTransition(ePS_WaitingForStream, tx);
1129     } else if (m_state == ePS_Running) {
1130         return scheduleStateTransition(ePS_WaitingForStreamDisable, tx);
1131     } else {
1132         debugError("Cannot switch to ePS_DryRunning from %s\n", ePSToString(m_state));
1133         return false;
1134     }
1135 }
1136
1137 bool StreamProcessor::scheduleStartRunning(int64_t t) {
1138     uint64_t tx;
1139     if (t < 0) {
1140         tx = addTicks(m_1394service.getCycleTimerTicks(), 200 * TICKS_PER_CYCLE);
1141     } else {
1142         tx = t;
1143     }
1144     debugOutput(DEBUG_LEVEL_VERBOSE,"for %s SP (%p)\n", ePTToString(getType()), this);
1145     uint64_t now = m_1394service.getCycleTimerTicks();
1146     debugOutput(DEBUG_LEVEL_VERBOSE,"  Now                   : %011llu (%03us %04uc %04ut)\n",
1147                           now,
1148                           (unsigned int)TICKS_TO_SECS(now),
1149                           (unsigned int)TICKS_TO_CYCLES(now),
1150                           (unsigned int)TICKS_TO_OFFSET(now));
1151     debugOutput(DEBUG_LEVEL_VERBOSE,"  Start at              : %011llu (%03us %04uc %04ut)\n",
1152                           tx,
1153                           (unsigned int)TICKS_TO_SECS(tx),
1154                           (unsigned int)TICKS_TO_CYCLES(tx),
1155                           (unsigned int)TICKS_TO_OFFSET(tx));
1156     return scheduleStateTransition(ePS_WaitingForStreamEnable, tx);
1157 }
1158
1159 bool StreamProcessor::scheduleStopDryRunning(int64_t t) {
1160     uint64_t tx;
1161     if (t < 0) {
1162         tx = addTicks(m_1394service.getCycleTimerTicks(), 200 * TICKS_PER_CYCLE);
1163     } else {
1164         tx = t;
1165     }
1166     debugOutput(DEBUG_LEVEL_VERBOSE,"for %s SP (%p)\n", ePTToString(getType()), this);
1167     uint64_t now = m_1394service.getCycleTimerTicks();
1168     debugOutput(DEBUG_LEVEL_VERBOSE,"  Now                   : %011llu (%03us %04uc %04ut)\n",
1169                           now,
1170                           (unsigned int)TICKS_TO_SECS(now),
1171                           (unsigned int)TICKS_TO_CYCLES(now),
1172                           (unsigned int)TICKS_TO_OFFSET(now));
1173     debugOutput(DEBUG_LEVEL_VERBOSE,"  Stop at               : %011llu (%03us %04uc %04ut)\n",
1174                           tx,
1175                           (unsigned int)TICKS_TO_SECS(tx),
1176                           (unsigned int)TICKS_TO_CYCLES(tx),
1177                           (unsigned int)TICKS_TO_OFFSET(tx));
1178
1179     return scheduleStateTransition(ePS_Stopped, tx);
1180 }
1181
1182 bool StreamProcessor::scheduleStopRunning(int64_t t) {
1183     uint64_t tx;
1184     if (t < 0) {
1185         tx = addTicks(m_1394service.getCycleTimerTicks(), 200 * TICKS_PER_CYCLE);
1186     } else {
1187         tx = t;
1188     }
1189     debugOutput(DEBUG_LEVEL_VERBOSE,"for %s SP (%p)\n", ePTToString(getType()), this);
1190     uint64_t now = m_1394service.getCycleTimerTicks();
1191     debugOutput(DEBUG_LEVEL_VERBOSE,"  Now                   : %011llu (%03us %04uc %04ut)\n",
1192                           now,
1193                           (unsigned int)TICKS_TO_SECS(now),
1194                           (unsigned int)TICKS_TO_CYCLES(now),
1195                           (unsigned int)TICKS_TO_OFFSET(now));
1196     debugOutput(DEBUG_LEVEL_VERBOSE,"  Stop at               : %011llu (%03us %04uc %04ut)\n",
1197                           tx,
1198                           (unsigned int)TICKS_TO_SECS(tx),
1199                           (unsigned int)TICKS_TO_CYCLES(tx),
1200                           (unsigned int)TICKS_TO_OFFSET(tx));
1201     return scheduleStateTransition(ePS_WaitingForStreamDisable, tx);
1202 }
1203
1204 bool StreamProcessor::startDryRunning(int64_t t) {
1205     if(!scheduleStartDryRunning(t)) {
1206         debugError("Could not schedule transition\n");
1207         return false;
1208     }
1209     if(!waitForState(ePS_DryRunning, 2000)) {
1210         debugError(" Timeout while waiting for %s\n", ePSToString(ePS_DryRunning));
1211         return false;
1212     }
1213     return true;
1214 }
1215
1216 bool StreamProcessor::startRunning(int64_t t) {
1217     if(!scheduleStartRunning(t)) {
1218         debugError("Could not schedule transition\n");
1219         return false;
1220     }
1221     if(!waitForState(ePS_Running, 2000)) {
1222         debugError(" Timeout while waiting for %s\n", ePSToString(ePS_Running));
1223         return false;
1224     }
1225     return true;
1226 }
1227
1228 bool StreamProcessor::stopDryRunning(int64_t t) {
1229     if(!scheduleStopDryRunning(t)) {
1230         debugError("Could not schedule transition\n");
1231         return false;
1232     }
1233     if(!waitForState(ePS_Stopped, 2000)) {
1234         debugError(" Timeout while waiting for %s\n", ePSToString(ePS_Stopped));
1235         return false;
1236     }
1237     return true;
1238 }
1239
1240 bool StreamProcessor::stopRunning(int64_t t) {
1241     if(!scheduleStopRunning(t)) {
1242         debugError("Could not schedule transition\n");
1243         return false;
1244     }
1245     if(!waitForState(ePS_DryRunning, 2000)) {
1246         debugError(" Timeout while waiting for %s\n", ePSToString(ePS_DryRunning));
1247         return false;
1248     }
1249     return true;
1250 }
1251
1252
1253 // internal state API
1254
1255 /**
1256  * @brief Enter the ePS_Stopped state
1257  * @return true if successful, false if not
1258  *
1259  * @pre none
1260  *
1261  * @post the buffer and the isostream are ready for use.
1262  * @post all dynamic structures have been allocated successfully
1263  * @post the buffer is transparent and empty, and all parameters are set
1264  *       to the correct initial/nominal values.
1265  *
1266  */
1267 bool
1268 StreamProcessor::doStop()
1269 {
1270     float ticks_per_frame;
1271     unsigned int ringbuffer_size_frames = (m_StreamProcessorManager.getNbBuffers() + 1) * m_StreamProcessorManager.getPeriodSize();
1272
1273     debugOutput(DEBUG_LEVEL_VERBOSE, "Enter from state: %s\n", ePSToString(m_state));
1274     bool result = true;
1275
1276     switch(m_state) {
1277         case ePS_Created:
1278             assert(m_data_buffer);
1279             // object just created
1280             result = m_data_buffer->init();
1281
1282             // prepare the framerate estimate
1283             ticks_per_frame = (TICKS_PER_SECOND*1.0) / ((float)m_StreamProcessorManager.getNominalRate());
1284             m_ticks_per_frame = ticks_per_frame;
1285             debugOutput(DEBUG_LEVEL_VERBOSE,"Initializing remote ticks/frame to %f\n", ticks_per_frame);
1286
1287             // initialize internal buffer
1288             result &= m_data_buffer->setBufferSize(ringbuffer_size_frames);
1289
1290             result &= m_data_buffer->setEventSize( getEventSize() );
1291             result &= m_data_buffer->setEventsPerFrame( getEventsPerFrame() );
1292             if(getType() == ePT_Receive) {
1293                 result &= m_data_buffer->setUpdatePeriod( getNominalFramesPerPacket() );
1294             } else {
1295                 result &= m_data_buffer->setUpdatePeriod( m_StreamProcessorManager.getPeriodSize() );
1296             }
1297             result &= m_data_buffer->setNominalRate(ticks_per_frame);
1298             result &= m_data_buffer->setWrapValue(128L*TICKS_PER_SECOND);
1299             result &= m_data_buffer->prepare(); // FIXME: the name
1300
1301             // set the parameters of ports we can:
1302             // we want the audio ports to be period buffered,
1303             // and the midi ports to be packet buffered
1304             for ( PortVectorIterator it = m_Ports.begin();
1305                 it != m_Ports.end();
1306                 ++it )
1307             {
1308                 debugOutput(DEBUG_LEVEL_VERBOSE, "Setting up port %s\n",(*it)->getName().c_str());
1309                 if(!(*it)->setBufferSize(m_StreamProcessorManager.getPeriodSize())) {
1310                     debugFatal("Could not set buffer size to %d\n",m_StreamProcessorManager.getPeriodSize());
1311                     return false;
1312                 }
1313             }
1314             // the API specific settings of the ports should already be set,
1315             // as this is called from the processorManager->prepare()
1316             // so we can init the ports
1317             result &= PortManager::initPorts();
1318
1319             break;
1320         case ePS_DryRunning:
1321             if(!m_IsoHandlerManager.stopHandlerForStream(this)) {
1322                 debugError("Could not stop handler for SP %p\n", this);
1323                 return false;
1324             }
1325             break;
1326         default:
1327             debugError("Entry from invalid state: %s\n", ePSToString(m_state));
1328             return false;
1329     }
1330
1331     result &= m_data_buffer->clearBuffer(); // FIXME: don't like the reset() name
1332     // make the buffer transparent
1333     m_data_buffer->setTransparent(true);
1334
1335     // reset all ports
1336     result &= PortManager::preparePorts();
1337
1338     m_state = ePS_Stopped;
1339     #ifdef DEBUG
1340     if (getDebugLevel() >= DEBUG_LEVEL_VERBOSE) {
1341         debugOutput(DEBUG_LEVEL_VERBOSE, "State switch complete, dumping SP info...\n");
1342         dumpInfo();
1343     }
1344     #endif
1345     return result;
1346 }
1347
1348 /**
1349  * @brief Enter the ePS_WaitingForStream state
1350  * @return true if successful, false if not
1351  *
1352  * @pre all dynamic data structures are allocated successfully
1353  *
1354  * @post
1355  *
1356  */
1357 bool
1358 StreamProcessor::doWaitForRunningStream()
1359 {
1360     debugOutput(DEBUG_LEVEL_VERBOSE, "Enter from state: %s\n", ePSToString(m_state));
1361     switch(m_state) {
1362         case ePS_Stopped:
1363             // we have to start waiting for an incoming stream
1364             // this basically means nothing, the state change will
1365             // be picked up by the packet iterator
1366             break;
1367         default:
1368             debugError("Entry from invalid state: %s\n", ePSToString(m_state));
1369             return false;
1370     }
1371     m_state = ePS_WaitingForStream;
1372     #ifdef DEBUG
1373     if (getDebugLevel() >= DEBUG_LEVEL_VERBOSE) {
1374         debugOutput(DEBUG_LEVEL_VERBOSE, "State switch complete, dumping SP info...\n");
1375         dumpInfo();
1376     }
1377     #endif
1378     return true;
1379 }
1380
1381 /**
1382  * @brief Enter the ePS_DryRunning state
1383  * @return true if successful, false if not
1384  *
1385  * @pre
1386  *
1387  * @post
1388  *
1389  */
1390 bool
1391 StreamProcessor::doDryRunning()
1392 {
1393     bool result = true;
1394     debugOutput(DEBUG_LEVEL_VERBOSE, "Enter from state: %s\n", ePSToString(m_state));
1395     switch(m_state) {
1396         case ePS_WaitingForStream:
1397             // a running stream has been detected
1398             debugOutput(DEBUG_LEVEL_VERBOSE, "StreamProcessor %p started dry-running at cycle %d\n", this, m_last_cycle);
1399             if (getType() == ePT_Receive) {
1400                 // this to ensure that there is no discontinuity when starting to
1401                 // update the DLL based upon the received packets
1402                 m_data_buffer->setBufferTailTimestamp(m_last_timestamp);
1403             } else {
1404                 // FIXME: PC=master mode will have to do something here I guess...
1405             }
1406             break;
1407         case ePS_WaitingForStreamEnable: // when xrunning at startup
1408             result &= m_data_buffer->clearBuffer();
1409             m_data_buffer->setTransparent(true);
1410             break;
1411         case ePS_WaitingForStreamDisable:
1412             result &= m_data_buffer->clearBuffer();
1413             m_data_buffer->setTransparent(true);
1414             break;
1415         default:
1416             debugError("Entry from invalid state: %s\n", ePSToString(m_state));
1417             return false;
1418     }
1419     m_state = ePS_DryRunning;
1420     #ifdef DEBUG
1421     if (getDebugLevel() >= DEBUG_LEVEL_VERBOSE) {
1422         debugOutput(DEBUG_LEVEL_VERBOSE, "State switch complete, dumping SP info...\n");
1423         dumpInfo();
1424     }
1425     #endif
1426     return result;
1427 }
1428
1429 /**
1430  * @brief Enter the ePS_WaitingForStreamEnable state
1431  * @return true if successful, false if not
1432  *
1433  * @pre
1434  *
1435  * @post
1436  *
1437  */
1438 bool
1439 StreamProcessor::doWaitForStreamEnable()
1440 {
1441     debugOutput(DEBUG_LEVEL_VERBOSE, "Enter from state: %s\n", ePSToString(m_state));
1442     unsigned int ringbuffer_size_frames;
1443     switch(m_state) {
1444         case ePS_DryRunning:
1445             // we have to start waiting for an incoming stream
1446             // this basically means nothing, the state change will
1447             // be picked up by the packet iterator
1448
1449             sem_init(&m_signal_semaphore, 0, 0);
1450             m_signal_period = m_StreamProcessorManager.getPeriodSize();
1451             m_signal_offset = 0; // FIXME: we have to ensure that everyone is ready
1452
1453             if(!m_data_buffer->clearBuffer()) {
1454                 debugError("Could not reset data buffer\n");
1455                 return false;
1456             }
1457             if (getType() == ePT_Transmit) {
1458                 ringbuffer_size_frames = m_StreamProcessorManager.getNbBuffers() * m_StreamProcessorManager.getPeriodSize();
1459                 debugOutput(DEBUG_LEVEL_VERBOSE, "Prefill transmit SP %p with %u frames\n", this, ringbuffer_size_frames);
1460                 // prefill the buffer
1461                 if(!transferSilence(ringbuffer_size_frames)) {
1462                     debugFatal("Could not prefill transmit stream\n");
1463                     return false;
1464                 }
1465                 if (m_data_buffer->getBufferFill() >= m_signal_period + m_signal_offset) {
1466                     POST_SEMAPHORE;
1467                 }
1468             }
1469
1470             break;
1471         default:
1472             debugError("Entry from invalid state: %s\n", ePSToString(m_state));
1473             return false;
1474     }
1475     m_state = ePS_WaitingForStreamEnable;
1476     #ifdef DEBUG
1477     if (getDebugLevel() >= DEBUG_LEVEL_VERBOSE) {
1478         debugOutput(DEBUG_LEVEL_VERBOSE, "State switch complete, dumping SP info...\n");
1479         dumpInfo();
1480     }
1481     #endif
1482     return true;
1483 }
1484
1485 /**
1486  * @brief Enter the ePS_Running state
1487  * @return true if successful, false if not
1488  *
1489  * @pre
1490  *
1491  * @post
1492  *
1493  */
1494 bool
1495 StreamProcessor::doRunning()
1496 {
1497     bool result = true;
1498     debugOutput(DEBUG_LEVEL_VERBOSE, "Enter from state: %s\n", ePSToString(m_state));
1499     switch(m_state) {
1500         case ePS_WaitingForStreamEnable:
1501             // a running stream has been detected
1502             debugOutput(DEBUG_LEVEL_VERBOSE, "StreamProcessor %p started running at cycle %d\n",
1503                                              this, m_last_cycle);
1504             m_in_xrun = false;
1505             m_data_buffer->setTransparent(false);
1506             break;
1507         default:
1508             debugError("Entry from invalid state: %s\n", ePSToString(m_state));
1509             return false;
1510     }
1511     m_state = ePS_Running;
1512     #ifdef DEBUG
1513     if (getDebugLevel() >= DEBUG_LEVEL_VERBOSE) {
1514         debugOutput(DEBUG_LEVEL_VERBOSE, "State switch complete, dumping SP info...\n");
1515         dumpInfo();
1516     }
1517     #endif
1518     return result;
1519 }
1520
1521 /**
1522  * @brief Enter the ePS_WaitingForStreamDisable state
1523  * @return true if successful, false if not
1524  *
1525  * @pre
1526  *
1527  * @post
1528  *
1529  */
1530 bool
1531 StreamProcessor::doWaitForStreamDisable()
1532 {
1533     debugOutput(DEBUG_LEVEL_VERBOSE, "Enter from state: %s\n", ePSToString(m_state));
1534     switch(m_state) {
1535         case ePS_Running:
1536             // the thread will do the transition
1537
1538             // we have to wake the iterator if it's asleep
1539             POST_SEMAPHORE;
1540             break;
1541         default:
1542             debugError("Entry from invalid state: %s\n", ePSToString(m_state));
1543             return false;
1544     }
1545     m_state = ePS_WaitingForStreamDisable;
1546     #ifdef DEBUG
1547     if (getDebugLevel() >= DEBUG_LEVEL_VERBOSE) {
1548         debugOutput(DEBUG_LEVEL_VERBOSE, "State switch complete, dumping SP info...\n");
1549         dumpInfo();
1550     }
1551     #endif
1552     return true;
1553 }
1554
1555 /**
1556  * @brief Updates the state machine and calls the necessary transition functions
1557  * @return true if successful, false if not
1558  */
1559 bool StreamProcessor::updateState() {
1560     bool result = false;
1561     // copy the current state locally since it could change value,
1562     // and that's something we don't want to happen inbetween tests
1563     // if m_next_state changes during this routine, we know for sure
1564     // that the previous state change was at least attempted correctly.
1565     enum eProcessorState next_state = m_next_state;
1566
1567     debugOutput(DEBUG_LEVEL_VERBOSE, "Do state transition: %s => %s\n",
1568         ePSToString(m_state), ePSToString(next_state));
1569
1570     if (m_state == next_state) {
1571         debugWarning("ignoring identity state update from/to %s\n", ePSToString(m_state) );
1572         return true;
1573     }
1574
1575     // after creation, only initialization is allowed
1576     if (m_state == ePS_Created) {
1577         if(next_state != ePS_Stopped) {
1578             goto updateState_exit_with_error;
1579         }
1580         // do init here
1581         result = doStop();
1582         if (result) return true;
1583         else goto updateState_exit_change_failed;
1584     }
1585
1586     // after initialization, only WaitingForRunningStream is allowed
1587     if (m_state == ePS_Stopped) {
1588         if(next_state != ePS_WaitingForStream) {
1589             goto updateState_exit_with_error;
1590         }
1591         result = doWaitForRunningStream();
1592         if (result) return true;
1593         else goto updateState_exit_change_failed;
1594     }
1595
1596     // after WaitingForStream, only ePS_DryRunning is allowed
1597     // this means that the stream started running
1598     if (m_state == ePS_WaitingForStream) {
1599         if(next_state != ePS_DryRunning) {
1600             goto updateState_exit_with_error;
1601         }
1602         result = doDryRunning();
1603         if (result) return true;
1604         else goto updateState_exit_change_failed;
1605     }
1606
1607     // from ePS_DryRunning we can go to:
1608     //   - ePS_Stopped if something went wrong during DryRunning
1609     //   - ePS_WaitingForStreamEnable if there is a requested to enable
1610     if (m_state == ePS_DryRunning) {
1611         if((next_state != ePS_Stopped) &&
1612            (next_state != ePS_WaitingForStreamEnable)) {
1613             goto updateState_exit_with_error;
1614         }
1615         if (next_state == ePS_Stopped) {
1616             result = doStop();
1617         } else {
1618             result = doWaitForStreamEnable();
1619         }
1620         if (result) return true;
1621         else goto updateState_exit_change_failed;
1622     }
1623
1624     // from ePS_WaitingForStreamEnable we can go to:
1625     //   - ePS_DryRunning if something went wrong while waiting
1626     //   - ePS_Running if the stream enabled correctly
1627     if (m_state == ePS_WaitingForStreamEnable) {
1628         if((next_state != ePS_DryRunning) &&
1629            (next_state != ePS_Running)) {
1630             goto updateState_exit_with_error;
1631         }
1632         if (next_state == ePS_Stopped) {
1633             result = doDryRunning();
1634         } else {
1635             result = doRunning();
1636         }
1637         if (result) return true;
1638         else goto updateState_exit_change_failed;
1639     }
1640
1641     // from ePS_Running we can only start waiting for a disabled stream
1642     if (m_state == ePS_Running) {
1643         if(next_state != ePS_WaitingForStreamDisable) {
1644             goto updateState_exit_with_error;
1645         }
1646         result = doWaitForStreamDisable();
1647         if (result) return true;
1648         else goto updateState_exit_change_failed;
1649     }
1650
1651     // from ePS_WaitingForStreamDisable we can go to DryRunning
1652     if (m_state == ePS_WaitingForStreamDisable) {
1653         if(next_state != ePS_DryRunning) {
1654             goto updateState_exit_with_error;
1655         }
1656         result = doDryRunning();
1657         if (result) return true;
1658         else goto updateState_exit_change_failed;
1659     }
1660
1661     // if we arrive here there is an error
1662 updateState_exit_with_error:
1663     debugError("Invalid state transition: %s => %s\n",
1664         ePSToString(m_state), ePSToString(next_state));
1665     return false;
1666 updateState_exit_change_failed:
1667     debugError("State transition failed: %s => %s\n",
1668         ePSToString(m_state), ePSToString(next_state));
1669     return false;
1670 }
1671
1672 /***********************************************
1673  * Helper routines                             *
1674  ***********************************************/
1675 bool
1676 StreamProcessor::transferSilence(unsigned int nframes)
1677 {
1678     bool retval;
1679     signed int fc;
1680     ffado_timestamp_t ts_tail_tmp;
1681
1682     // prepare a buffer of silence
1683     char *dummybuffer = (char *)calloc(getEventSize(), nframes * getEventsPerFrame());
1684     transmitSilenceBlock(dummybuffer, nframes, 0);
1685
1686     m_data_buffer->getBufferTailTimestamp(&ts_tail_tmp, &fc);
1687     if (fc != 0) {
1688         debugWarning("Prefilling a buffer that already contains %d frames\n", fc);
1689     }
1690
1691     // add the silence data to the ringbuffer
1692     if(m_data_buffer->preloadFrames(nframes, dummybuffer, true)) {
1693         retval = true;
1694     } else {
1695         debugWarning("Could not write to event buffer\n");
1696         retval = false;
1697     }
1698     free(dummybuffer);
1699     return retval;
1700 }
1701
1702 /**
1703  * @brief convert a eProcessorState to a string
1704  * @param s the state
1705  * @return a char * describing the state
1706  */
1707 const char *
1708 StreamProcessor::ePSToString(enum eProcessorState s) {
1709     switch (s) {
1710         case ePS_Invalid: return "ePS_Invalid";
1711         case ePS_Created: return "ePS_Created";
1712         case ePS_Stopped: return "ePS_Stopped";
1713         case ePS_WaitingForStream: return "ePS_WaitingForStream";
1714         case ePS_DryRunning: return "ePS_DryRunning";
1715         case ePS_WaitingForStreamEnable: return "ePS_WaitingForStreamEnable";
1716         case ePS_Running: return "ePS_Running";
1717         case ePS_WaitingForStreamDisable: return "ePS_WaitingForStreamDisable";
1718         default: return "error: unknown state";
1719     }
1720 }
1721
1722 /**
1723  * @brief convert a eProcessorType to a string
1724  * @param t the type
1725  * @return a char * describing the state
1726  */
1727 const char *
1728 StreamProcessor::ePTToString(enum eProcessorType t) {
1729     switch (t) {
1730         case ePT_Receive: return "Receive";
1731         case ePT_Transmit: return "Transmit";
1732         default: return "error: unknown type";
1733     }
1734 }
1735
1736 /***********************************************
1737  * Debug                                       *
1738  ***********************************************/
1739 void
1740 StreamProcessor::dumpInfo()
1741 {
1742     debugOutputShort( DEBUG_LEVEL_NORMAL, " StreamProcessor %p, %s:\n", this, ePTToString(m_processor_type));
1743     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Port, Channel  : %d, %d\n", m_1394service.getPort(), m_channel);
1744     uint64_t now = m_1394service.getCycleTimerTicks();
1745     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Now                   : %011llu (%03us %04uc %04ut)\n",
1746                         now,
1747                         (unsigned int)TICKS_TO_SECS(now),
1748                         (unsigned int)TICKS_TO_CYCLES(now),
1749                         (unsigned int)TICKS_TO_OFFSET(now));
1750     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Xrun?                 : %s\n", (m_in_xrun ? "True":"False"));
1751     if (m_state == m_next_state) {
1752         debugOutputShort( DEBUG_LEVEL_NORMAL, "  State                 : %s\n",
1753                                             ePSToString(m_state));
1754     } else {
1755         debugOutputShort( DEBUG_LEVEL_NORMAL, "  State                 : %s (Next: %s)\n",
1756                                               ePSToString(m_state), ePSToString(m_next_state));
1757         debugOutputShort( DEBUG_LEVEL_NORMAL, "    transition at       : %u\n", m_cycle_to_switch_state);
1758     }
1759     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Buffer                : %p\n", m_data_buffer);
1760     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Framerate             : Nominal: %u, Sync: %f, Buffer %f\n",
1761                                           m_StreamProcessorManager.getNominalRate(),
1762                                           24576000.0/m_StreamProcessorManager.getSyncSource().m_data_buffer->getRate(),
1763                                           24576000.0/m_data_buffer->getRate());
1764     float d = getSyncDelay();
1765     debugOutputShort(DEBUG_LEVEL_NORMAL, "  Sync delay             : %f ticks (%f frames, %f cy)\n",
1766                                          d, d/getTicksPerFrame(),
1767                                          d/((float)TICKS_PER_CYCLE));
1768     m_data_buffer->dumpInfo();
1769 }
1770
1771 void
1772 StreamProcessor::setVerboseLevel(int l) {
1773     setDebugLevel(l);
1774     PortManager::setVerboseLevel(l);
1775     m_data_buffer->setVerboseLevel(l);
1776 }
1777
1778 } // end of namespace
Note: See TracBrowser for help on using the browser.