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

Revision 815, 66.5 kB (checked in by ppalmers, 13 years ago)

- AMDTP transmit port caching for better performance
- less debug output in critical path

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->getDataType()) {
983         default:
984             debugError("Invalid port type: %d\n", p->getDataType());
985             return -1;
986         case Port::E_Int24:
987         case Port::E_MidiEvent:
988         case Port::E_ControlEvent:
989             {
990                 quadlet_t *buffer=(quadlet_t *)(p->getBufferAddress());
991                 assert(nevents + offset <= p->getBufferSize());
992                 buffer+=offset;
993
994                 for(j = 0; j < nevents; j += 1) {
995                     *(buffer)=0;
996                     buffer++;
997                 }
998             }
999             break;
1000         case Port::E_Float:
1001             {
1002                 float *buffer=(float *)(p->getBufferAddress());
1003                 assert(nevents + offset <= p->getBufferSize());
1004                 buffer+=offset;
1005
1006                 for(j = 0; j < nevents; j += 1) {
1007                     *buffer = 0.0;
1008                     buffer++;
1009                 }
1010             }
1011             break;
1012     }
1013     return 0;
1014 }
1015
1016 /***********************************************
1017  * State related API                           *
1018  ***********************************************/
1019 bool StreamProcessor::init()
1020 {
1021     debugOutput( DEBUG_LEVEL_VERY_VERBOSE, "init...\n");
1022
1023     if (sem_init(&m_signal_semaphore, 0, 0) == -1) {
1024         debugError("Could not init signal semaphore");
1025         return false;
1026     }
1027
1028     if(!m_IsoHandlerManager.registerStream(this)) {
1029         debugOutput(DEBUG_LEVEL_VERBOSE,"Could not register stream processor with the Iso manager\n");
1030         return false;
1031     }
1032     if(!m_StreamProcessorManager.registerProcessor(this)) {
1033         debugOutput(DEBUG_LEVEL_VERBOSE,"Could not register stream processor with the SP manager\n");
1034         return false;
1035     }
1036
1037     // initialization can be done without requesting it
1038     // from the packet loop
1039     m_next_state = ePS_Created;
1040     return true;
1041 }
1042
1043 bool StreamProcessor::prepare()
1044 {
1045     debugOutput( DEBUG_LEVEL_VERBOSE, "Prepare SP (%p)...\n", this);
1046
1047     // make the scratch buffer one period of frames long
1048     m_scratch_buffer_size_bytes = m_StreamProcessorManager.getPeriodSize() * getEventsPerFrame() * getEventSize();
1049     debugOutput( DEBUG_LEVEL_VERBOSE, " Allocate scratch buffer of %d quadlets\n");
1050     if(m_scratch_buffer) delete[] m_scratch_buffer;
1051     m_scratch_buffer = new byte_t[m_scratch_buffer_size_bytes];
1052     if(m_scratch_buffer == NULL) {
1053         debugFatal("Could not allocate scratch buffer\n");
1054         return false;
1055     }
1056
1057     // set the parameters of ports we can:
1058     // we want the audio ports to be period buffered,
1059     // and the midi ports to be packet buffered
1060     for ( PortVectorIterator it = m_Ports.begin();
1061         it != m_Ports.end();
1062         ++it )
1063     {
1064         debugOutput(DEBUG_LEVEL_VERBOSE, "Setting up port %s\n",(*it)->getName().c_str());
1065         if(!(*it)->setBufferSize(m_StreamProcessorManager.getPeriodSize())) {
1066             debugFatal("Could not set buffer size to %d\n",m_StreamProcessorManager.getPeriodSize());
1067             return false;
1068         }
1069     }
1070     // the API specific settings of the ports should already be set,
1071     // as this is called from the processorManager->prepare()
1072     // so we can init the ports
1073     if(!PortManager::initPorts()) {
1074         debugFatal("Could not initialize ports\n");
1075         return false;
1076     }
1077
1078     if (!prepareChild()) {
1079         debugFatal("Could not prepare child\n");
1080         return false;
1081     }
1082
1083     debugOutput( DEBUG_LEVEL_VERBOSE, "Prepared for:\n");
1084     debugOutput( DEBUG_LEVEL_VERBOSE, " Samplerate: %d\n",
1085              m_StreamProcessorManager.getNominalRate());
1086     debugOutput( DEBUG_LEVEL_VERBOSE, " PeriodSize: %d, NbBuffers: %d\n",
1087              m_StreamProcessorManager.getPeriodSize(), m_StreamProcessorManager.getNbBuffers());
1088     debugOutput( DEBUG_LEVEL_VERBOSE, " Port: %d, Channel: %d\n",
1089              m_1394service.getPort(), m_channel);
1090
1091     // initialization can be done without requesting it
1092     // from the packet loop
1093     m_next_state = ePS_Stopped;
1094     return updateState();
1095 }
1096
1097 bool
1098 StreamProcessor::scheduleStateTransition(enum eProcessorState state, uint64_t time_instant)
1099 {
1100     // first set the time, since in the packet loop we first check m_state == m_next_state before
1101     // using the time
1102     m_cycle_to_switch_state = TICKS_TO_CYCLES(time_instant);
1103     m_next_state = state;
1104     return true;
1105 }
1106
1107 bool
1108 StreamProcessor::waitForState(enum eProcessorState state, unsigned int timeout_ms)
1109 {
1110     debugOutput(DEBUG_LEVEL_VERBOSE, "Waiting for state %s\n", ePSToString(state));
1111     int cnt = timeout_ms;
1112     while (m_state != state && cnt) {
1113         SleepRelativeUsec(1000);
1114         cnt--;
1115     }
1116     if(cnt==0) {
1117         debugOutput(DEBUG_LEVEL_VERBOSE, " Timeout\n");
1118         return false;
1119     }
1120     return true;
1121 }
1122
1123 bool StreamProcessor::scheduleStartDryRunning(int64_t t) {
1124     uint64_t tx;
1125     if (t < 0) {
1126         tx = addTicks(m_1394service.getCycleTimerTicks(), 200 * TICKS_PER_CYCLE);
1127     } else {
1128         tx = t;
1129     }
1130     uint64_t start_handler_ticks = substractTicks(tx, 100 * TICKS_PER_CYCLE);
1131
1132     debugOutput(DEBUG_LEVEL_VERBOSE,"for %s SP (%p)\n", ePTToString(getType()), this);
1133     uint64_t now = m_1394service.getCycleTimerTicks();
1134     debugOutput(DEBUG_LEVEL_VERBOSE,"  Now                   : %011llu (%03us %04uc %04ut)\n",
1135                           now,
1136                           (unsigned int)TICKS_TO_SECS(now),
1137                           (unsigned int)TICKS_TO_CYCLES(now),
1138                           (unsigned int)TICKS_TO_OFFSET(now));
1139     debugOutput(DEBUG_LEVEL_VERBOSE,"  Start at              : %011llu (%03us %04uc %04ut)\n",
1140                           tx,
1141                           (unsigned int)TICKS_TO_SECS(tx),
1142                           (unsigned int)TICKS_TO_CYCLES(tx),
1143                           (unsigned int)TICKS_TO_OFFSET(tx));
1144     if (m_state == ePS_Stopped) {
1145         if(!m_IsoHandlerManager.startHandlerForStream(
1146                                         this, TICKS_TO_CYCLES(start_handler_ticks))) {
1147             debugError("Could not start handler for SP %p\n", this);
1148             return false;
1149         }
1150         return scheduleStateTransition(ePS_WaitingForStream, tx);
1151     } else if (m_state == ePS_Running) {
1152         return scheduleStateTransition(ePS_WaitingForStreamDisable, tx);
1153     } else {
1154         debugError("Cannot switch to ePS_DryRunning from %s\n", ePSToString(m_state));
1155         return false;
1156     }
1157 }
1158
1159 bool StreamProcessor::scheduleStartRunning(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,"  Start 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     return scheduleStateTransition(ePS_WaitingForStreamEnable, tx);
1179 }
1180
1181 bool StreamProcessor::scheduleStopDryRunning(int64_t t) {
1182     uint64_t tx;
1183     if (t < 0) {
1184         tx = addTicks(m_1394service.getCycleTimerTicks(), 200 * TICKS_PER_CYCLE);
1185     } else {
1186         tx = t;
1187     }
1188     debugOutput(DEBUG_LEVEL_VERBOSE,"for %s SP (%p)\n", ePTToString(getType()), this);
1189     uint64_t now = m_1394service.getCycleTimerTicks();
1190     debugOutput(DEBUG_LEVEL_VERBOSE,"  Now                   : %011llu (%03us %04uc %04ut)\n",
1191                           now,
1192                           (unsigned int)TICKS_TO_SECS(now),
1193                           (unsigned int)TICKS_TO_CYCLES(now),
1194                           (unsigned int)TICKS_TO_OFFSET(now));
1195     debugOutput(DEBUG_LEVEL_VERBOSE,"  Stop at               : %011llu (%03us %04uc %04ut)\n",
1196                           tx,
1197                           (unsigned int)TICKS_TO_SECS(tx),
1198                           (unsigned int)TICKS_TO_CYCLES(tx),
1199                           (unsigned int)TICKS_TO_OFFSET(tx));
1200
1201     return scheduleStateTransition(ePS_Stopped, tx);
1202 }
1203
1204 bool StreamProcessor::scheduleStopRunning(int64_t t) {
1205     uint64_t tx;
1206     if (t < 0) {
1207         tx = addTicks(m_1394service.getCycleTimerTicks(), 200 * TICKS_PER_CYCLE);
1208     } else {
1209         tx = t;
1210     }
1211     debugOutput(DEBUG_LEVEL_VERBOSE,"for %s SP (%p)\n", ePTToString(getType()), this);
1212     uint64_t now = m_1394service.getCycleTimerTicks();
1213     debugOutput(DEBUG_LEVEL_VERBOSE,"  Now                   : %011llu (%03us %04uc %04ut)\n",
1214                           now,
1215                           (unsigned int)TICKS_TO_SECS(now),
1216                           (unsigned int)TICKS_TO_CYCLES(now),
1217                           (unsigned int)TICKS_TO_OFFSET(now));
1218     debugOutput(DEBUG_LEVEL_VERBOSE,"  Stop at               : %011llu (%03us %04uc %04ut)\n",
1219                           tx,
1220                           (unsigned int)TICKS_TO_SECS(tx),
1221                           (unsigned int)TICKS_TO_CYCLES(tx),
1222                           (unsigned int)TICKS_TO_OFFSET(tx));
1223     return scheduleStateTransition(ePS_WaitingForStreamDisable, tx);
1224 }
1225
1226 bool StreamProcessor::startDryRunning(int64_t t) {
1227     if(!scheduleStartDryRunning(t)) {
1228         debugError("Could not schedule transition\n");
1229         return false;
1230     }
1231     if(!waitForState(ePS_DryRunning, 2000)) {
1232         debugError(" Timeout while waiting for %s\n", ePSToString(ePS_DryRunning));
1233         return false;
1234     }
1235     return true;
1236 }
1237
1238 bool StreamProcessor::startRunning(int64_t t) {
1239     if(!scheduleStartRunning(t)) {
1240         debugError("Could not schedule transition\n");
1241         return false;
1242     }
1243     if(!waitForState(ePS_Running, 2000)) {
1244         debugError(" Timeout while waiting for %s\n", ePSToString(ePS_Running));
1245         return false;
1246     }
1247     return true;
1248 }
1249
1250 bool StreamProcessor::stopDryRunning(int64_t t) {
1251     if(!scheduleStopDryRunning(t)) {
1252         debugError("Could not schedule transition\n");
1253         return false;
1254     }
1255     if(!waitForState(ePS_Stopped, 2000)) {
1256         debugError(" Timeout while waiting for %s\n", ePSToString(ePS_Stopped));
1257         return false;
1258     }
1259     return true;
1260 }
1261
1262 bool StreamProcessor::stopRunning(int64_t t) {
1263     if(!scheduleStopRunning(t)) {
1264         debugError("Could not schedule transition\n");
1265         return false;
1266     }
1267     if(!waitForState(ePS_DryRunning, 2000)) {
1268         debugError(" Timeout while waiting for %s\n", ePSToString(ePS_DryRunning));
1269         return false;
1270     }
1271     return true;
1272 }
1273
1274
1275 // internal state API
1276
1277 /**
1278  * @brief Enter the ePS_Stopped state
1279  * @return true if successful, false if not
1280  *
1281  * @pre none
1282  *
1283  * @post the buffer and the isostream are ready for use.
1284  * @post all dynamic structures have been allocated successfully
1285  * @post the buffer is transparent and empty, and all parameters are set
1286  *       to the correct initial/nominal values.
1287  *
1288  */
1289 bool
1290 StreamProcessor::doStop()
1291 {
1292     float ticks_per_frame;
1293     unsigned int ringbuffer_size_frames = (m_StreamProcessorManager.getNbBuffers() + 1) * m_StreamProcessorManager.getPeriodSize();
1294
1295     debugOutput(DEBUG_LEVEL_VERBOSE, "Enter from state: %s\n", ePSToString(m_state));
1296     bool result = true;
1297
1298     switch(m_state) {
1299         case ePS_Created:
1300             assert(m_data_buffer);
1301
1302             // prepare the framerate estimate
1303             ticks_per_frame = (TICKS_PER_SECOND*1.0) / ((float)m_StreamProcessorManager.getNominalRate());
1304             m_ticks_per_frame = ticks_per_frame;
1305             debugOutput(DEBUG_LEVEL_VERBOSE,"Initializing remote ticks/frame to %f\n", ticks_per_frame);
1306
1307             // initialize internal buffer
1308             result &= m_data_buffer->setBufferSize(ringbuffer_size_frames);
1309
1310             result &= m_data_buffer->setEventSize( getEventSize() );
1311             result &= m_data_buffer->setEventsPerFrame( getEventsPerFrame() );
1312             if(getType() == ePT_Receive) {
1313                 result &= m_data_buffer->setUpdatePeriod( getNominalFramesPerPacket() );
1314             } else {
1315                 result &= m_data_buffer->setUpdatePeriod( m_StreamProcessorManager.getPeriodSize() );
1316             }
1317             result &= m_data_buffer->setNominalRate(ticks_per_frame);
1318             result &= m_data_buffer->setWrapValue(128L*TICKS_PER_SECOND);
1319             result &= m_data_buffer->prepare(); // FIXME: the name
1320
1321             break;
1322         case ePS_DryRunning:
1323             if(!m_IsoHandlerManager.stopHandlerForStream(this)) {
1324                 debugError("Could not stop handler for SP %p\n", this);
1325                 return false;
1326             }
1327             break;
1328         default:
1329             debugError("Entry from invalid state: %s\n", ePSToString(m_state));
1330             return false;
1331     }
1332
1333     result &= m_data_buffer->clearBuffer(); // FIXME: don't like the reset() name
1334     // make the buffer transparent
1335     m_data_buffer->setTransparent(true);
1336
1337     // reset all ports
1338     result &= PortManager::preparePorts();
1339
1340     m_state = ePS_Stopped;
1341     #ifdef DEBUG
1342     if (getDebugLevel() >= DEBUG_LEVEL_VERBOSE) {
1343         debugOutput(DEBUG_LEVEL_VERBOSE, "State switch complete, dumping SP info...\n");
1344         dumpInfo();
1345     }
1346     #endif
1347     return result;
1348 }
1349
1350 /**
1351  * @brief Enter the ePS_WaitingForStream state
1352  * @return true if successful, false if not
1353  *
1354  * @pre all dynamic data structures are allocated successfully
1355  *
1356  * @post
1357  *
1358  */
1359 bool
1360 StreamProcessor::doWaitForRunningStream()
1361 {
1362     debugOutput(DEBUG_LEVEL_VERBOSE, "Enter from state: %s\n", ePSToString(m_state));
1363     switch(m_state) {
1364         case ePS_Stopped:
1365             // we have to start waiting for an incoming stream
1366             // this basically means nothing, the state change will
1367             // be picked up by the packet iterator
1368             break;
1369         default:
1370             debugError("Entry from invalid state: %s\n", ePSToString(m_state));
1371             return false;
1372     }
1373     m_state = ePS_WaitingForStream;
1374     #ifdef DEBUG
1375     if (getDebugLevel() >= DEBUG_LEVEL_VERBOSE) {
1376         debugOutput(DEBUG_LEVEL_VERBOSE, "State switch complete, dumping SP info...\n");
1377         dumpInfo();
1378     }
1379     #endif
1380     return true;
1381 }
1382
1383 /**
1384  * @brief Enter the ePS_DryRunning state
1385  * @return true if successful, false if not
1386  *
1387  * @pre
1388  *
1389  * @post
1390  *
1391  */
1392 bool
1393 StreamProcessor::doDryRunning()
1394 {
1395     bool result = true;
1396     debugOutput(DEBUG_LEVEL_VERBOSE, "Enter from state: %s\n", ePSToString(m_state));
1397     switch(m_state) {
1398         case ePS_WaitingForStream:
1399             // a running stream has been detected
1400             debugOutput(DEBUG_LEVEL_VERBOSE, "StreamProcessor %p started dry-running at cycle %d\n", this, m_last_cycle);
1401             if (getType() == ePT_Receive) {
1402                 // this to ensure that there is no discontinuity when starting to
1403                 // update the DLL based upon the received packets
1404                 m_data_buffer->setBufferTailTimestamp(m_last_timestamp);
1405             } else {
1406                 // FIXME: PC=master mode will have to do something here I guess...
1407             }
1408             break;
1409         case ePS_WaitingForStreamEnable: // when xrunning at startup
1410             result &= m_data_buffer->clearBuffer();
1411             m_data_buffer->setTransparent(true);
1412             break;
1413         case ePS_WaitingForStreamDisable:
1414             result &= m_data_buffer->clearBuffer();
1415             m_data_buffer->setTransparent(true);
1416             break;
1417         default:
1418             debugError("Entry from invalid state: %s\n", ePSToString(m_state));
1419             return false;
1420     }
1421     m_state = ePS_DryRunning;
1422     #ifdef DEBUG
1423     if (getDebugLevel() >= DEBUG_LEVEL_VERBOSE) {
1424         debugOutput(DEBUG_LEVEL_VERBOSE, "State switch complete, dumping SP info...\n");
1425         dumpInfo();
1426     }
1427     #endif
1428     return result;
1429 }
1430
1431 /**
1432  * @brief Enter the ePS_WaitingForStreamEnable state
1433  * @return true if successful, false if not
1434  *
1435  * @pre
1436  *
1437  * @post
1438  *
1439  */
1440 bool
1441 StreamProcessor::doWaitForStreamEnable()
1442 {
1443     debugOutput(DEBUG_LEVEL_VERBOSE, "Enter from state: %s\n", ePSToString(m_state));
1444     unsigned int ringbuffer_size_frames;
1445     switch(m_state) {
1446         case ePS_DryRunning:
1447             // we have to start waiting for an incoming stream
1448             // this basically means nothing, the state change will
1449             // be picked up by the packet iterator
1450
1451             sem_init(&m_signal_semaphore, 0, 0);
1452             m_signal_period = m_StreamProcessorManager.getPeriodSize();
1453             m_signal_offset = 0; // FIXME: we have to ensure that everyone is ready
1454
1455             if(!m_data_buffer->clearBuffer()) {
1456                 debugError("Could not reset data buffer\n");
1457                 return false;
1458             }
1459             if (getType() == ePT_Transmit) {
1460                 ringbuffer_size_frames = m_StreamProcessorManager.getNbBuffers() * m_StreamProcessorManager.getPeriodSize();
1461                 debugOutput(DEBUG_LEVEL_VERBOSE, "Prefill transmit SP %p with %u frames\n", this, ringbuffer_size_frames);
1462                 // prefill the buffer
1463                 if(!transferSilence(ringbuffer_size_frames)) {
1464                     debugFatal("Could not prefill transmit stream\n");
1465                     return false;
1466                 }
1467                 if (m_data_buffer->getBufferFill() >= m_signal_period + m_signal_offset) {
1468                     POST_SEMAPHORE;
1469                 }
1470             }
1471
1472             break;
1473         default:
1474             debugError("Entry from invalid state: %s\n", ePSToString(m_state));
1475             return false;
1476     }
1477     m_state = ePS_WaitingForStreamEnable;
1478     #ifdef DEBUG
1479     if (getDebugLevel() >= DEBUG_LEVEL_VERBOSE) {
1480         debugOutput(DEBUG_LEVEL_VERBOSE, "State switch complete, dumping SP info...\n");
1481         dumpInfo();
1482     }
1483     #endif
1484     return true;
1485 }
1486
1487 /**
1488  * @brief Enter the ePS_Running state
1489  * @return true if successful, false if not
1490  *
1491  * @pre
1492  *
1493  * @post
1494  *
1495  */
1496 bool
1497 StreamProcessor::doRunning()
1498 {
1499     bool result = true;
1500     debugOutput(DEBUG_LEVEL_VERBOSE, "Enter from state: %s\n", ePSToString(m_state));
1501     switch(m_state) {
1502         case ePS_WaitingForStreamEnable:
1503             // a running stream has been detected
1504             debugOutput(DEBUG_LEVEL_VERBOSE, "StreamProcessor %p started running at cycle %d\n",
1505                                              this, m_last_cycle);
1506             m_in_xrun = false;
1507             m_data_buffer->setTransparent(false);
1508             break;
1509         default:
1510             debugError("Entry from invalid state: %s\n", ePSToString(m_state));
1511             return false;
1512     }
1513     m_state = ePS_Running;
1514     #ifdef DEBUG
1515     if (getDebugLevel() >= DEBUG_LEVEL_VERBOSE) {
1516         debugOutput(DEBUG_LEVEL_VERBOSE, "State switch complete, dumping SP info...\n");
1517         dumpInfo();
1518     }
1519     #endif
1520     return result;
1521 }
1522
1523 /**
1524  * @brief Enter the ePS_WaitingForStreamDisable state
1525  * @return true if successful, false if not
1526  *
1527  * @pre
1528  *
1529  * @post
1530  *
1531  */
1532 bool
1533 StreamProcessor::doWaitForStreamDisable()
1534 {
1535     debugOutput(DEBUG_LEVEL_VERBOSE, "Enter from state: %s\n", ePSToString(m_state));
1536     switch(m_state) {
1537         case ePS_Running:
1538             // the thread will do the transition
1539
1540             // we have to wake the iterator if it's asleep
1541             POST_SEMAPHORE;
1542             break;
1543         default:
1544             debugError("Entry from invalid state: %s\n", ePSToString(m_state));
1545             return false;
1546     }
1547     m_state = ePS_WaitingForStreamDisable;
1548     #ifdef DEBUG
1549     if (getDebugLevel() >= DEBUG_LEVEL_VERBOSE) {
1550         debugOutput(DEBUG_LEVEL_VERBOSE, "State switch complete, dumping SP info...\n");
1551         dumpInfo();
1552     }
1553     #endif
1554     return true;
1555 }
1556
1557 /**
1558  * @brief Updates the state machine and calls the necessary transition functions
1559  * @return true if successful, false if not
1560  */
1561 bool StreamProcessor::updateState() {
1562     bool result = false;
1563     // copy the current state locally since it could change value,
1564     // and that's something we don't want to happen inbetween tests
1565     // if m_next_state changes during this routine, we know for sure
1566     // that the previous state change was at least attempted correctly.
1567     enum eProcessorState next_state = m_next_state;
1568
1569     debugOutput(DEBUG_LEVEL_VERBOSE, "Do state transition: %s => %s\n",
1570         ePSToString(m_state), ePSToString(next_state));
1571
1572     if (m_state == next_state) {
1573         debugWarning("ignoring identity state update from/to %s\n", ePSToString(m_state) );
1574         return true;
1575     }
1576
1577     // after creation, only initialization is allowed
1578     if (m_state == ePS_Created) {
1579         if(next_state != ePS_Stopped) {
1580             goto updateState_exit_with_error;
1581         }
1582         // do init here
1583         result = doStop();
1584         if (result) return true;
1585         else goto updateState_exit_change_failed;
1586     }
1587
1588     // after initialization, only WaitingForRunningStream is allowed
1589     if (m_state == ePS_Stopped) {
1590         if(next_state != ePS_WaitingForStream) {
1591             goto updateState_exit_with_error;
1592         }
1593         result = doWaitForRunningStream();
1594         if (result) return true;
1595         else goto updateState_exit_change_failed;
1596     }
1597
1598     // after WaitingForStream, only ePS_DryRunning is allowed
1599     // this means that the stream started running
1600     if (m_state == ePS_WaitingForStream) {
1601         if(next_state != ePS_DryRunning) {
1602             goto updateState_exit_with_error;
1603         }
1604         result = doDryRunning();
1605         if (result) return true;
1606         else goto updateState_exit_change_failed;
1607     }
1608
1609     // from ePS_DryRunning we can go to:
1610     //   - ePS_Stopped if something went wrong during DryRunning
1611     //   - ePS_WaitingForStreamEnable if there is a requested to enable
1612     if (m_state == ePS_DryRunning) {
1613         if((next_state != ePS_Stopped) &&
1614            (next_state != ePS_WaitingForStreamEnable)) {
1615             goto updateState_exit_with_error;
1616         }
1617         if (next_state == ePS_Stopped) {
1618             result = doStop();
1619         } else {
1620             result = doWaitForStreamEnable();
1621         }
1622         if (result) return true;
1623         else goto updateState_exit_change_failed;
1624     }
1625
1626     // from ePS_WaitingForStreamEnable we can go to:
1627     //   - ePS_DryRunning if something went wrong while waiting
1628     //   - ePS_Running if the stream enabled correctly
1629     if (m_state == ePS_WaitingForStreamEnable) {
1630         if((next_state != ePS_DryRunning) &&
1631            (next_state != ePS_Running)) {
1632             goto updateState_exit_with_error;
1633         }
1634         if (next_state == ePS_Stopped) {
1635             result = doDryRunning();
1636         } else {
1637             result = doRunning();
1638         }
1639         if (result) return true;
1640         else goto updateState_exit_change_failed;
1641     }
1642
1643     // from ePS_Running we can only start waiting for a disabled stream
1644     if (m_state == ePS_Running) {
1645         if(next_state != ePS_WaitingForStreamDisable) {
1646             goto updateState_exit_with_error;
1647         }
1648         result = doWaitForStreamDisable();
1649         if (result) return true;
1650         else goto updateState_exit_change_failed;
1651     }
1652
1653     // from ePS_WaitingForStreamDisable we can go to DryRunning
1654     if (m_state == ePS_WaitingForStreamDisable) {
1655         if(next_state != ePS_DryRunning) {
1656             goto updateState_exit_with_error;
1657         }
1658         result = doDryRunning();
1659         if (result) return true;
1660         else goto updateState_exit_change_failed;
1661     }
1662
1663     // if we arrive here there is an error
1664 updateState_exit_with_error:
1665     debugError("Invalid state transition: %s => %s\n",
1666         ePSToString(m_state), ePSToString(next_state));
1667     return false;
1668 updateState_exit_change_failed:
1669     debugError("State transition failed: %s => %s\n",
1670         ePSToString(m_state), ePSToString(next_state));
1671     return false;
1672 }
1673
1674 /***********************************************
1675  * Helper routines                             *
1676  ***********************************************/
1677 bool
1678 StreamProcessor::transferSilence(unsigned int nframes)
1679 {
1680     bool retval;
1681     signed int fc;
1682     ffado_timestamp_t ts_tail_tmp;
1683
1684     // prepare a buffer of silence
1685     char *dummybuffer = (char *)calloc(getEventSize(), nframes * getEventsPerFrame());
1686     transmitSilenceBlock(dummybuffer, nframes, 0);
1687
1688     m_data_buffer->getBufferTailTimestamp(&ts_tail_tmp, &fc);
1689     if (fc != 0) {
1690         debugWarning("Prefilling a buffer that already contains %d frames\n", fc);
1691     }
1692
1693     // add the silence data to the ringbuffer
1694     if(m_data_buffer->preloadFrames(nframes, dummybuffer, true)) {
1695         retval = true;
1696     } else {
1697         debugWarning("Could not write to event buffer\n");
1698         retval = false;
1699     }
1700     free(dummybuffer);
1701     return retval;
1702 }
1703
1704 /**
1705  * @brief convert a eProcessorState to a string
1706  * @param s the state
1707  * @return a char * describing the state
1708  */
1709 const char *
1710 StreamProcessor::ePSToString(enum eProcessorState s) {
1711     switch (s) {
1712         case ePS_Invalid: return "ePS_Invalid";
1713         case ePS_Created: return "ePS_Created";
1714         case ePS_Stopped: return "ePS_Stopped";
1715         case ePS_WaitingForStream: return "ePS_WaitingForStream";
1716         case ePS_DryRunning: return "ePS_DryRunning";
1717         case ePS_WaitingForStreamEnable: return "ePS_WaitingForStreamEnable";
1718         case ePS_Running: return "ePS_Running";
1719         case ePS_WaitingForStreamDisable: return "ePS_WaitingForStreamDisable";
1720         default: return "error: unknown state";
1721     }
1722 }
1723
1724 /**
1725  * @brief convert a eProcessorType to a string
1726  * @param t the type
1727  * @return a char * describing the state
1728  */
1729 const char *
1730 StreamProcessor::ePTToString(enum eProcessorType t) {
1731     switch (t) {
1732         case ePT_Receive: return "Receive";
1733         case ePT_Transmit: return "Transmit";
1734         default: return "error: unknown type";
1735     }
1736 }
1737
1738 /***********************************************
1739  * Debug                                       *
1740  ***********************************************/
1741 void
1742 StreamProcessor::dumpInfo()
1743 {
1744     debugOutputShort( DEBUG_LEVEL_NORMAL, " StreamProcessor %p, %s:\n", this, ePTToString(m_processor_type));
1745     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Port, Channel  : %d, %d\n", m_1394service.getPort(), m_channel);
1746     uint64_t now = m_1394service.getCycleTimerTicks();
1747     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Now                   : %011llu (%03us %04uc %04ut)\n",
1748                         now,
1749                         (unsigned int)TICKS_TO_SECS(now),
1750                         (unsigned int)TICKS_TO_CYCLES(now),
1751                         (unsigned int)TICKS_TO_OFFSET(now));
1752     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Xrun?                 : %s\n", (m_in_xrun ? "True":"False"));
1753     if (m_state == m_next_state) {
1754         debugOutputShort( DEBUG_LEVEL_NORMAL, "  State                 : %s\n",
1755                                             ePSToString(m_state));
1756     } else {
1757         debugOutputShort( DEBUG_LEVEL_NORMAL, "  State                 : %s (Next: %s)\n",
1758                                               ePSToString(m_state), ePSToString(m_next_state));
1759         debugOutputShort( DEBUG_LEVEL_NORMAL, "    transition at       : %u\n", m_cycle_to_switch_state);
1760     }
1761     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Buffer                : %p\n", m_data_buffer);
1762     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Framerate             : Nominal: %u, Sync: %f, Buffer %f\n",
1763                                           m_StreamProcessorManager.getNominalRate(),
1764                                           24576000.0/m_StreamProcessorManager.getSyncSource().m_data_buffer->getRate(),
1765                                           24576000.0/m_data_buffer->getRate());
1766     float d = getSyncDelay();
1767     debugOutputShort(DEBUG_LEVEL_NORMAL, "  Sync delay             : %f ticks (%f frames, %f cy)\n",
1768                                          d, d/getTicksPerFrame(),
1769                                          d/((float)TICKS_PER_CYCLE));
1770     m_data_buffer->dumpInfo();
1771 }
1772
1773 void
1774 StreamProcessor::setVerboseLevel(int l) {
1775     setDebugLevel(l);
1776     PortManager::setVerboseLevel(l);
1777     m_data_buffer->setVerboseLevel(l);
1778 }
1779
1780 } // end of namespace
Note: See TracBrowser for help on using the browser.