root/branches/libffado-2.0/src/libstreaming/generic/StreamProcessor.cpp

Revision 1526, 73.8 kB (checked in by ppalmers, 12 years ago)

fix the freewheeling issue. clean up the IsoHandler? and the interactions with the Manager.

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