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

Revision 1530, 74.5 kB (checked in by ppalmers, 15 years ago)

- make the sync delay an integer amount of packets to avoid phase issues
- debug message updates

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_frames( 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 ticks) {
212
213     // round the sync delay to an integer number of packets now we know the frame rate
214     int frames = (int)((float)ticks / getTicksPerFrame());
215     frames = (frames / getNominalFramesPerPacket()) + 1;
216     frames *= getNominalFramesPerPacket();
217    
218     #ifdef DEBUG
219     float ticks2 = frames * getTicksPerFrame();
220     debugOutput(DEBUG_LEVEL_VERBOSE, "Setting SP %p SyncDelay to %u ticks => rounded to %u frames, %f ticks\n",
221                 this, ticks, frames, ticks2);
222     #endif
223     m_sync_delay_frames = frames;
224 }
225
226 unsigned int
227 StreamProcessor::getSyncDelayFrames() {
228     return m_sync_delay_frames;
229 }
230
231 unsigned int
232 StreamProcessor::getSyncDelay() {
233     return (unsigned int)(m_sync_delay_frames * getTicksPerFrame());
234 }
235
236 uint64_t
237 StreamProcessor::getTimeAtPeriodUsecs()
238 {
239     return (uint64_t)((float)getTimeAtPeriod() * TICKS_PER_USEC);
240 }
241
242 uint64_t
243 StreamProcessor::getTimeAtPeriod()
244 {
245     if (getType() == ePT_Receive) {
246         ffado_timestamp_t next_period_boundary = m_data_buffer->getTimestampFromHead(m_StreamProcessorManager.getPeriodSize());
247    
248         #ifdef DEBUG
249         ffado_timestamp_t ts;
250         signed int fc;
251         m_data_buffer->getBufferTailTimestamp(&ts,&fc);
252    
253         debugOutput(DEBUG_LEVEL_VERY_VERBOSE, "=> NPD="TIMESTAMP_FORMAT_SPEC", LTS="TIMESTAMP_FORMAT_SPEC", FC=%5u, TPF=%f\n",
254             next_period_boundary, ts, fc, getTicksPerFrame()
255             );
256         #endif
257         return (uint64_t)next_period_boundary;
258     } else {
259         ffado_timestamp_t next_period_boundary = m_data_buffer->getTimestampFromTail((m_StreamProcessorManager.getNbBuffers()-1) * m_StreamProcessorManager.getPeriodSize());
260    
261         #ifdef DEBUG
262         ffado_timestamp_t ts;
263         signed int fc;
264         m_data_buffer->getBufferTailTimestamp(&ts,&fc);
265    
266         debugOutput(DEBUG_LEVEL_VERY_VERBOSE, "=> NPD="TIMESTAMP_FORMAT_SPEC", LTS="TIMESTAMP_FORMAT_SPEC", FC=%5u, TPF=%f\n",
267             next_period_boundary, ts, fc, getTicksPerFrame()
268             );
269         #endif
270         return (uint64_t)next_period_boundary;
271     }
272 }
273
274 float
275 StreamProcessor::getTicksPerFrame()
276 {
277     assert(m_data_buffer != NULL);
278     return m_data_buffer->getRate();
279 }
280
281 void
282 StreamProcessor::setTicksPerFrame(float tpf)
283 {
284     assert(m_data_buffer != NULL);
285     m_data_buffer->setRate(tpf);
286 }
287
288 bool
289 StreamProcessor::setDllBandwidth(float bw)
290 {
291     m_dll_bandwidth_hz = bw;
292     return true;
293 }
294
295 bool
296 StreamProcessor::canClientTransferFrames(unsigned int nbframes)
297 {
298     bool can_transfer;
299     unsigned int fc = m_data_buffer->getFrameCounter();
300     if (getType() == ePT_Receive) {
301         can_transfer = (fc >= nbframes);
302     } else {
303         // there has to be enough space to put the frames in
304         can_transfer = m_data_buffer->getBufferSize() - fc > nbframes;
305         // or the buffer is transparent
306         can_transfer |= m_data_buffer->isTransparent();
307     }
308    
309     #ifdef DEBUG
310     if (!can_transfer) {
311         debugOutput(DEBUG_LEVEL_VERBOSE, "(%p, %s) cannot transfer since fc == %u, nbframes == %u\n",
312             this, ePTToString(getType()), fc, nbframes);
313     }
314     #endif
315    
316     return can_transfer;
317 }
318
319 /***********************************************
320  * I/O API                                     *
321  ***********************************************/
322
323 // Packet transfer API
324 enum raw1394_iso_disposition
325 StreamProcessor::putPacket(unsigned char *data, unsigned int length,
326                            unsigned char channel, unsigned char tag, unsigned char sy,
327                            uint32_t pkt_ctr,
328                            unsigned int dropped_cycles) {
329     // bypass based upon state
330 #ifdef DEBUG
331     if (m_state == ePS_Invalid) {
332         debugError("Should not have state %s\n", ePSToString(m_state) );
333         return RAW1394_ISO_ERROR;
334     }
335 #endif
336     // FIXME: isn't this also an error condition?
337     if (m_state == ePS_Created) {
338         return RAW1394_ISO_DEFER;
339     }
340
341     if (m_state == ePS_Error) {
342         debugOutputExtreme(DEBUG_LEVEL_VERBOSE, "skip due to error state\n");
343         return RAW1394_ISO_OK;
344     }
345
346     // store the previous timestamp
347     m_last_timestamp2 = m_last_timestamp;
348
349     // NOTE: synchronized switching is restricted to a 0.5 sec span (4000 cycles)
350     //       it happens on the first 'good' cycle for the wait condition
351     //       or on the first received cycle that is received afterwards (might be a problem)
352
353     // check whether we are waiting for a stream to be disabled
354     if(m_state == ePS_WaitingForStreamDisable) {
355         // we then check whether we have to switch on this cycle
356         if (diffCycles(CYCLE_TIMER_GET_CYCLES(pkt_ctr), m_cycle_to_switch_state) >= 0) {
357             debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to DryRunning\n");
358             m_next_state = ePS_DryRunning;
359             if (!updateState()) { // we are allowed to change the state directly
360                 debugError("Could not update state!\n");
361                 return RAW1394_ISO_ERROR;
362             }
363         } else {
364             // not time to disable yet
365         }
366         // the received data can be discarded while waiting for the stream
367         // to be disabled
368         // similarly for dropped packets
369         return RAW1394_ISO_OK;
370     }
371
372     // check whether we are waiting for a stream to be enabled
373     else if(m_state == ePS_WaitingForStreamEnable
374             && m_next_state == ePS_WaitingForStreamEnable) {
375         // we then check whether we have to switch on this cycle
376         if (diffCycles(CYCLE_TIMER_GET_CYCLES(pkt_ctr), m_cycle_to_switch_state) >= 0) {
377             debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to Running\n");
378             m_next_state = ePS_Running;
379             if (!updateState()) { // we are allowed to change the state directly
380                 debugError("Could not update state!\n");
381                 return RAW1394_ISO_ERROR;
382             }
383         } else {
384             // not time to enable yet
385         }
386         // we are dryRunning hence data should be processed in any case
387     }
388
389     // check the packet header
390     enum eChildReturnValue result = processPacketHeader(data, length, tag, sy, pkt_ctr);
391
392     // handle dropped cycles
393     if(dropped_cycles) {
394         // make sure the last_timestamp is corrected
395         m_correct_last_timestamp = true;
396         if (m_state == ePS_Running) {
397             // this is an xrun situation
398             m_in_xrun = true;
399             debugOutput(DEBUG_LEVEL_NORMAL, "Should update state to WaitingForStreamDisable due to dropped packet xrun\n");
400             m_cycle_to_switch_state = CYCLE_TIMER_GET_CYCLES(pkt_ctr) + 1; // switch in the next cycle
401             m_next_state = ePS_WaitingForStreamDisable;
402             // execute the requested change
403             if (!updateState()) { // we are allowed to change the state directly
404                 debugError("Could not update state!\n");
405                 return RAW1394_ISO_ERROR;
406             }
407         }
408     }
409
410     if (result == eCRV_OK) {
411         #ifdef DEBUG
412         if (m_last_timestamp > 0 && m_last_timestamp2 > 0) {
413             int64_t tsp_diff = diffTicks(m_last_timestamp, m_last_timestamp2);
414             debugOutputExtreme(DEBUG_LEVEL_VERBOSE, "TSP diff: %lld\n", tsp_diff);
415             double tsp_diff_d = tsp_diff;
416             double fs_syt = 1.0/tsp_diff_d;
417             fs_syt *= (double)getNominalFramesPerPacket() * (double)TICKS_PER_USEC * 1e6;
418             double fs_nom = (double)m_StreamProcessorManager.getNominalRate();
419             double fs_diff = fs_nom - fs_syt;
420             double fs_diff_norm = fs_diff/fs_nom;
421             debugOutputExtreme(DEBUG_LEVEL_VERBOSE, "Nom fs: %12f, Instantanous fs: %12f, diff: %12f (%12f)\n",
422                         fs_nom, fs_syt, fs_diff, fs_diff_norm);
423             if (fs_diff_norm > 0.01 || fs_diff_norm < -0.01) {
424                 debugWarning( "Instantanous samplerate more than 1%% off nominal. [Nom fs: %12f, Instantanous fs: %12f, diff: %12f (%12f)]\n",
425                         fs_nom, fs_syt, fs_diff, fs_diff_norm);
426             }
427
428             int ticks_per_packet = (int)(getTicksPerFrame() * getNominalFramesPerPacket());
429             int diff = diffTicks(m_last_timestamp, m_last_timestamp2);
430                 // display message if the difference between two successive tick
431                 // values is more than 50 ticks. 1 sample at 48k is 512 ticks
432                 // so 50 ticks = 10%, which is a rather large jitter value.
433                 if(diff-ticks_per_packet > 50 || diff-ticks_per_packet < -50) {
434                     debugOutput(DEBUG_LEVEL_VERBOSE,
435                                 "cy %04u rather large TSP difference TS=%011llu => TS=%011llu (%d, nom %d)\n",
436                                 CYCLE_TIMER_GET_CYCLES(pkt_ctr), m_last_timestamp2,
437                                 m_last_timestamp, diff, ticks_per_packet);
438                     // !!!HACK!!! FIXME: this is the result of a failure in wrapping/unwrapping somewhere
439                     // it's definitely a bug.
440                     // try to fix up the timestamp
441                     int64_t last_timestamp_fixed;
442                     // first try to add one second
443                     last_timestamp_fixed = addTicks(m_last_timestamp, TICKS_PER_SECOND);
444                     diff = diffTicks(last_timestamp_fixed, m_last_timestamp2);
445                     if(diff-ticks_per_packet < 50 && diff-ticks_per_packet > -50) {
446                         debugWarning("cy %04u rather large TSP difference TS=%011llu => TS=%011llu (%d, nom %d)\n",
447                                     CYCLE_TIMER_GET_CYCLES(pkt_ctr), m_last_timestamp2,
448                                     m_last_timestamp, diff, ticks_per_packet);
449                         debugWarning("HACK: fixed by adding one second of ticks. This is a bug being run-time fixed.\n");
450                         m_last_timestamp = last_timestamp_fixed;
451                     } else {
452                         // if that didn't work, try to subtract one second
453                         last_timestamp_fixed = substractTicks(m_last_timestamp, TICKS_PER_SECOND);
454                         diff = diffTicks(last_timestamp_fixed, m_last_timestamp2);
455                         if(diff-ticks_per_packet < 50 && diff-ticks_per_packet > -50) {
456                             debugWarning("cy %04u rather large TSP difference TS=%011llu => TS=%011llu (%d, nom %d)\n",
457                                         CYCLE_TIMER_GET_CYCLES(pkt_ctr), m_last_timestamp2,
458                                         m_last_timestamp, diff, ticks_per_packet);
459                             debugWarning("HACK: fixed by subtracing one second of ticks. This is a bug being run-time fixed.\n");
460                             m_last_timestamp = last_timestamp_fixed;
461                         }
462                     }
463                 }
464                 debugOutputExtreme(DEBUG_LEVEL_VERY_VERBOSE,
465                                 "%04u %011llu %011llu %d %d\n",
466                                 CYCLE_TIMER_GET_CYCLES(pkt_ctr),
467                                 m_last_timestamp2, m_last_timestamp,
468                                 diff, ticks_per_packet);
469         }
470         #endif
471
472         debugOutputExtreme(DEBUG_LEVEL_VERY_VERBOSE,
473                           "RECV: CY=%04u TS=%011llu\n",
474                           CYCLE_TIMER_GET_CYCLES(pkt_ctr),
475                           m_last_timestamp);
476
477         if(m_correct_last_timestamp) {
478             // they represent a discontinuity in the timestamps, and hence are
479             // to be dealt with
480             debugOutput(DEBUG_LEVEL_NORMAL, "(%p) Correcting timestamp for dropped cycles, discarding packet...\n", this);
481             m_data_buffer->setBufferTailTimestamp(substractTicks(m_last_timestamp,
482                                                                  (uint64_t)(getNominalFramesPerPacket()
483                                                                             * getTicksPerFrame())));
484             m_correct_last_timestamp = false;
485         }
486
487         // check whether we are waiting for a stream to startup
488         // this requires that the packet is good
489         if(m_state == ePS_WaitingForStream) {
490             // since we have a packet with an OK header,
491             // we can indicate that the stream started up
492
493             // we then check whether we have to switch on this cycle
494             if (diffCycles(CYCLE_TIMER_GET_CYCLES(pkt_ctr), m_cycle_to_switch_state) >= 0) {
495                 debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to DryRunning due to good packet\n");
496                 // hence go to the dryRunning state
497                 m_next_state = ePS_DryRunning;
498                 if (!updateState()) { // we are allowed to change the state directly
499                     debugError("Could not update state!\n");
500                     return RAW1394_ISO_ERROR;
501                 }
502             } else {
503                 // not time (yet) to switch state
504             }
505             // in both cases we don't want to process the data
506             return RAW1394_ISO_OK;
507         }
508
509         // check whether a state change has been requested
510         // note that only the wait state changes are synchronized with the cycles
511         else if(m_state != m_next_state) {
512             debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state from %s to %s\n",
513                                              ePSToString(m_state), ePSToString(m_next_state));
514             // execute the requested change
515             if (!updateState()) { // we are allowed to change the state directly
516                 debugError("Could not update state!\n");
517                 return RAW1394_ISO_ERROR;
518             }
519         }
520
521         // for all states that reach this we are allowed to
522         // do protocol specific data reception
523         enum eChildReturnValue result2 = processPacketData(data, length);
524
525         // if an xrun occured, switch to the dryRunning state and
526         // allow for the xrun to be picked up
527         if (result2 == eCRV_XRun) {
528             debugOutput(DEBUG_LEVEL_NORMAL, "processPacketData xrun\n");
529             m_in_xrun = true;
530             debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to WaitingForStreamDisable due to data xrun\n");
531             m_cycle_to_switch_state = CYCLE_TIMER_GET_CYCLES(pkt_ctr)+1; // switch in the next cycle
532             m_next_state = ePS_WaitingForStreamDisable;
533             // execute the requested change
534             if (!updateState()) { // we are allowed to change the state directly
535                 debugError("Could not update state!\n");
536                 return RAW1394_ISO_ERROR;
537             }
538             return RAW1394_ISO_DEFER;
539         } else if(result2 == eCRV_OK) {
540             return RAW1394_ISO_OK;
541         } else {
542             debugError("Invalid response\n");
543             return RAW1394_ISO_ERROR;
544         }
545     } else if(result == eCRV_Invalid) {
546         // apparently we don't have to do anything when the packets are not valid
547         return RAW1394_ISO_OK;
548     } else {
549         debugError("Invalid response\n");
550         return RAW1394_ISO_ERROR;
551     }
552     debugError("reached the unreachable\n");
553     return RAW1394_ISO_ERROR;
554 }
555
556 enum raw1394_iso_disposition
557 StreamProcessor::getPacket(unsigned char *data, unsigned int *length,
558                            unsigned char *tag, unsigned char *sy,
559                            uint32_t pkt_ctr, unsigned int dropped_cycles,
560                            unsigned int skipped, unsigned int max_length) {
561     if (pkt_ctr == 0xFFFFFFFF) {
562         *tag = 0;
563         *sy = 0;
564         *length = 0;
565         return RAW1394_ISO_OK;
566     }
567
568     if (m_state == ePS_Error) {
569         debugOutputExtreme(DEBUG_LEVEL_VERBOSE, "skip due to error state\n");
570         return RAW1394_ISO_OK;
571     }
572
573     uint64_t prev_timestamp;
574     // note that we can ignore skipped cycles since
575     // the protocol will take care of that
576     if (dropped_cycles > 0) {
577         // HACK: this should not be necessary, since the header generation functions should trigger the xrun.
578         //       but apparently there are some issues with the 1394 stack
579         m_in_xrun = true;
580         if(m_state == ePS_Running) {
581             debugShowBackLogLines(200);
582             debugOutput(DEBUG_LEVEL_NORMAL, "dropped packets xrun (%u)\n", dropped_cycles);
583             debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to WaitingForStreamDisable due to dropped packets xrun\n");
584             m_cycle_to_switch_state = CYCLE_TIMER_GET_CYCLES(pkt_ctr) + 1;
585             m_next_state = ePS_WaitingForStreamDisable;
586             // execute the requested change
587             if (!updateState()) { // we are allowed to change the state directly
588                 debugError("Could not update state!\n");
589                 return RAW1394_ISO_ERROR;
590             }
591             goto send_empty_packet;
592         }
593     }
594
595 #ifdef DEBUG
596     // bypass based upon state
597     if (m_state == ePS_Invalid) {
598         debugError("Should not have state %s\n", ePSToString(m_state) );
599         return RAW1394_ISO_ERROR;
600     }
601 #endif
602
603     // FIXME: can this happen?
604     if (m_state == ePS_Created) {
605         *tag = 0;
606         *sy = 0;
607         *length = 0;
608         return RAW1394_ISO_DEFER;
609     }
610
611     // normal processing
612
613     // store the previous timestamp
614     // keep the old value here, update m_last_timestamp2 only when
615     // a valid packet will be sent
616     prev_timestamp = m_last_timestamp;
617
618     // NOTE: synchronized switching is restricted to a 0.5 sec span (4000 cycles)
619     //       it happens on the first 'good' cycle for the wait condition
620     //       or on the first received cycle that is received afterwards (might be a problem)
621
622     // check whether we are waiting for a stream to be disabled
623     if(m_state == ePS_WaitingForStreamDisable) {
624         // we then check whether we have to switch on this cycle
625         if (diffCycles(CYCLE_TIMER_GET_CYCLES(pkt_ctr), m_cycle_to_switch_state) >= 0) {
626             debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to DryRunning\n");
627             m_next_state = ePS_DryRunning;
628             if (!updateState()) { // we are allowed to change the state directly
629                 debugError("Could not update state!\n");
630                 return RAW1394_ISO_ERROR;
631             }
632         }
633         // generate the silent packet header
634         enum eChildReturnValue result = generateSilentPacketHeader(data, length, tag, sy, pkt_ctr);
635         if (result == eCRV_Packet) {
636             debugOutputExtreme(DEBUG_LEVEL_VERY_VERBOSE,
637                                "XMIT SILENT: CY=%04u TS=%011llu\n",
638                                CYCLE_TIMER_GET_CYCLES(pkt_ctr), m_last_timestamp);
639
640             // assumed not to xrun
641             generateSilentPacketData(data, length);
642             return RAW1394_ISO_OK;
643         // FIXME: PP: I think this [empty packet] should also be a possibility
644         // JMW: yes, it should.  MOTU needs it for a clean shutdown.
645         } else if (result == eCRV_EmptyPacket) {
646             goto send_empty_packet;
647         } else {
648             debugError("Invalid return value: %d\n", result);
649             return RAW1394_ISO_ERROR;
650         }
651     }
652     // check whether we are waiting for a stream to be enabled
653     else if(m_state == ePS_WaitingForStreamEnable
654             && m_next_state == ePS_WaitingForStreamEnable) {
655         // we then check whether we have to switch on this cycle
656         if (diffCycles(CYCLE_TIMER_GET_CYCLES(pkt_ctr), m_cycle_to_switch_state) >= 0) {
657             debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to Running\n");
658             m_next_state = ePS_Running;
659             if (!updateState()) { // we are allowed to change the state directly
660                 debugError("Could not update state!\n");
661                 return RAW1394_ISO_ERROR;
662             }
663         } else {
664             // not time to enable yet
665         }
666         // we are dryRunning hence data should be processed in any case
667     }
668     // check whether we are waiting for a stream to startup
669     else if(m_state == ePS_WaitingForStream) {
670         // check whether we have to switch on this cycle
671         if ((diffCycles(CYCLE_TIMER_GET_CYCLES(pkt_ctr), m_cycle_to_switch_state) >= 0)) {
672             debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to WaitingForStream to DryRunning\n");
673             // hence go to the dryRunning state
674             m_next_state = ePS_DryRunning;
675             if (!updateState()) { // we are allowed to change the state directly
676                 debugError("Could not update state!\n");
677                 return RAW1394_ISO_ERROR;
678             }
679         } else {
680             // not time (yet) to switch state
681         }
682     }
683     else if(m_state == ePS_Running) {
684         // check the packet header
685         enum eChildReturnValue result = generatePacketHeader(data, length, tag, sy, pkt_ctr);
686         if (result == eCRV_Packet || result == eCRV_Defer) {
687             debugOutputExtreme(DEBUG_LEVEL_VERBOSE,
688                                "XMIT: CY=%04u TS=%011llu\n",
689                                CYCLE_TIMER_GET_CYCLES(pkt_ctr), m_last_timestamp);
690
691             // valid packet timestamp
692             m_last_timestamp2 = prev_timestamp;
693
694             // check whether a state change has been requested
695             // note that only the wait state changes are synchronized with the cycles
696             if(m_state != m_next_state) {
697                 debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state from %s to %s\n",
698                                                 ePSToString(m_state), ePSToString(m_next_state));
699                 // execute the requested change
700                 if (!updateState()) { // we are allowed to change the state directly
701                     debugError("Could not update state!\n");
702                     return RAW1394_ISO_ERROR;
703                 }
704             }
705
706             enum eChildReturnValue result2 = generatePacketData(data, length);
707             // if an xrun occured, switch to the dryRunning state and
708             // allow for the xrun to be picked up
709             if (result2 == eCRV_XRun) {
710                 debugOutput(DEBUG_LEVEL_NORMAL, "generatePacketData xrun\n");
711                 m_in_xrun = true;
712                 debugOutput(DEBUG_LEVEL_VERBOSE, "Should update state to WaitingForStreamDisable due to data xrun\n");
713                 m_cycle_to_switch_state = CYCLE_TIMER_GET_CYCLES(pkt_ctr) + 1; // switch in the next cycle
714                 m_next_state = ePS_WaitingForStreamDisable;
715                 // execute the requested change
716                 if (!updateState()) { // we are allowed to change the state directly
717                     debugError("Could not update state!\n");
718                     return RAW1394_ISO_ERROR;
719                 }
720                 goto send_empty_packet;
721             }
722             #ifdef DEBUG
723             if (m_last_timestamp > 0 && m_last_timestamp2 > 0) {
724                 int64_t tsp_diff = diffTicks(m_last_timestamp, m_last_timestamp2);
725                 debugOutputExtreme(DEBUG_LEVEL_VERBOSE, "TSP diff: %lld\n", tsp_diff);
726                 double tsp_diff_d = tsp_diff;
727                 double fs_syt = 1.0/tsp_diff_d;
728                 fs_syt *= (double)getNominalFramesPerPacket() * (double)TICKS_PER_USEC * 1e6;
729                 double fs_nom = (double)m_StreamProcessorManager.getNominalRate();
730                 double fs_diff = fs_nom - fs_syt;
731                 double fs_diff_norm = fs_diff/fs_nom;
732                 debugOutputExtreme(DEBUG_LEVEL_VERBOSE, "Nom fs: %12f, Instantanous fs: %12f, diff: %12f (%12f)\n",
733                            fs_nom, fs_syt, fs_diff, fs_diff_norm);
734 //                 debugOutput(DEBUG_LEVEL_VERBOSE, "Diff fs: %12f, m_last_timestamp: %011llu, m_last_timestamp2: %011llu\n",
735 //                            fs_diff, m_last_timestamp, m_last_timestamp2);
736                 if (fs_diff_norm > 0.01 || fs_diff_norm < -0.01) {
737                     debugWarning( "Instantanous samplerate more than 1%% off nominal. [Nom fs: %12f, Instantanous fs: %12f, diff: %12f (%12f)]\n",
738                            fs_nom, fs_syt, fs_diff, fs_diff_norm);
739                 }
740                 int ticks_per_packet = (int)(getTicksPerFrame() * getNominalFramesPerPacket());
741                 int diff = diffTicks(m_last_timestamp, m_last_timestamp2);
742                 // display message if the difference between two successive tick
743                 // values is more than 50 ticks. 1 sample at 48k is 512 ticks
744                 // so 50 ticks = 10%, which is a rather large jitter value.
745                 if(diff-ticks_per_packet > 50 || diff-ticks_per_packet < -50) {
746                     debugOutput(DEBUG_LEVEL_VERBOSE,
747                                 "cy %04d, rather large TSP difference TS=%011llu => TS=%011llu (%d, nom %d)\n",
748                                 CYCLE_TIMER_GET_CYCLES(pkt_ctr), m_last_timestamp2,
749                                 m_last_timestamp, diff, ticks_per_packet);
750                 }
751                 debugOutputExtreme(DEBUG_LEVEL_VERY_VERBOSE,
752                                 "%04d %011llu %011llu %d %d\n",
753                                 CYCLE_TIMER_GET_CYCLES(pkt_ctr), m_last_timestamp2,
754                                 m_last_timestamp, diff, ticks_per_packet);
755             }
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(STREAMPROCESSOR_DLL_FAST_BW_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 (sync_delay_frames = %d)\n",
1565                             this, ringbuffer_size_frames, syncdelay_in_frames);
1566                 // prefill the buffer
1567                 if(!transferSilence(ringbuffer_size_frames)) {
1568                     debugFatal("Could not prefill transmit stream\n");
1569                     return false;
1570                 }
1571             }
1572             break;
1573         default:
1574             debugError("Entry from invalid state: %s\n", ePSToString(m_state));
1575             return false;
1576     }
1577     m_state = ePS_WaitingForStreamEnable;
1578     #ifdef DEBUG
1579     if (getDebugLevel() >= DEBUG_LEVEL_VERBOSE) {
1580         debugOutput(DEBUG_LEVEL_VERBOSE, "State switch complete, dumping SP info...\n");
1581         dumpInfo();
1582     }
1583     #endif
1584     SIGNAL_ACTIVITY_ALL;
1585     return true;
1586 }
1587
1588 /**
1589  * @brief Enter the ePS_Running state
1590  * @return true if successful, false if not
1591  *
1592  * @pre
1593  *
1594  * @post
1595  *
1596  */
1597 bool
1598 StreamProcessor::doRunning()
1599 {
1600     bool result = true;
1601     debugOutput(DEBUG_LEVEL_VERBOSE, "Enter from state: %s\n", ePSToString(m_state));
1602     switch(m_state) {
1603         case ePS_WaitingForStreamEnable:
1604             // a running stream has been detected
1605             debugOutput(DEBUG_LEVEL_VERBOSE, "StreamProcessor %p started running\n",
1606                                              this);
1607             m_in_xrun = false;
1608             m_local_node_id = m_1394service.getLocalNodeId() & 0x3f;
1609             // reduce the DLL bandwidth to what we require
1610             result &= m_data_buffer->setBandwidth(m_dll_bandwidth_hz / (double)TICKS_PER_SECOND);
1611             // enable the data buffer
1612             m_data_buffer->setTransparent(false);
1613             m_last_timestamp2 = 0; // NOTE: no use in checking if we just started running
1614             break;
1615         default:
1616             debugError("Entry from invalid state: %s\n", ePSToString(m_state));
1617             return false;
1618     }
1619     m_state = ePS_Running;
1620     #ifdef DEBUG
1621     if (getDebugLevel() >= DEBUG_LEVEL_VERBOSE) {
1622         debugOutput(DEBUG_LEVEL_VERBOSE, "State switch complete, dumping SP info...\n");
1623         dumpInfo();
1624     }
1625     #endif
1626     SIGNAL_ACTIVITY_ALL;
1627     return result;
1628 }
1629
1630 /**
1631  * @brief Enter the ePS_WaitingForStreamDisable state
1632  * @return true if successful, false if not
1633  *
1634  * @pre
1635  *
1636  * @post
1637  *
1638  */
1639 bool
1640 StreamProcessor::doWaitForStreamDisable()
1641 {
1642     debugOutput(DEBUG_LEVEL_VERBOSE, "Enter from state: %s\n", ePSToString(m_state));
1643     switch(m_state) {
1644         case ePS_Running:
1645             // the thread will do the transition
1646             break;
1647         default:
1648             debugError("Entry from invalid state: %s\n", ePSToString(m_state));
1649             return false;
1650     }
1651     m_state = ePS_WaitingForStreamDisable;
1652     #ifdef DEBUG
1653     if (getDebugLevel() >= DEBUG_LEVEL_VERBOSE) {
1654         debugOutput(DEBUG_LEVEL_VERBOSE, "State switch complete, dumping SP info...\n");
1655         dumpInfo();
1656     }
1657     #endif
1658     SIGNAL_ACTIVITY_ALL;
1659     return true;
1660 }
1661
1662 /**
1663  * @brief Updates the state machine and calls the necessary transition functions
1664  * @return true if successful, false if not
1665  */
1666 bool StreamProcessor::updateState() {
1667     bool result = false;
1668     // copy the current state locally since it could change value,
1669     // and that's something we don't want to happen inbetween tests
1670     // if m_next_state changes during this routine, we know for sure
1671     // that the previous state change was at least attempted correctly.
1672     enum eProcessorState next_state = m_next_state;
1673
1674     debugOutput(DEBUG_LEVEL_VERBOSE, "Do state transition: %s => %s\n",
1675         ePSToString(m_state), ePSToString(next_state));
1676
1677     if (m_state == next_state) {
1678         debugWarning("ignoring identity state update from/to %s\n", ePSToString(m_state) );
1679         return true;
1680     }
1681     // after creation, only initialization is allowed
1682     if (m_state == ePS_Created) {
1683         if(next_state != ePS_Stopped) {
1684             goto updateState_exit_with_error;
1685         }
1686         // do init here
1687         result = doStop();
1688         if (result) {return true;}
1689         else goto updateState_exit_change_failed;
1690     }
1691
1692     // after initialization, only WaitingForRunningStream is allowed
1693     if (m_state == ePS_Stopped) {
1694         if(next_state != ePS_WaitingForStream) {
1695             goto updateState_exit_with_error;
1696         }
1697         result = doWaitForRunningStream();
1698         if (result) {return true;}
1699         else goto updateState_exit_change_failed;
1700     }
1701
1702     // after WaitingForStream, only ePS_DryRunning is allowed
1703     // this means that the stream started running
1704     if (m_state == ePS_WaitingForStream) {
1705         if(next_state != ePS_DryRunning) {
1706             goto updateState_exit_with_error;
1707         }
1708         result = doDryRunning();
1709         if (result) {return true;}
1710         else goto updateState_exit_change_failed;
1711     }
1712
1713     // from ePS_DryRunning we can go to:
1714     //   - ePS_Stopped if something went wrong during DryRunning
1715     //   - ePS_WaitingForStreamEnable if there is a requested to enable
1716     if (m_state == ePS_DryRunning) {
1717         if((next_state != ePS_Stopped) &&
1718            (next_state != ePS_WaitingForStreamEnable)) {
1719             goto updateState_exit_with_error;
1720         }
1721         if (next_state == ePS_Stopped) {
1722             result = doStop();
1723         } else {
1724             result = doWaitForStreamEnable();
1725         }
1726         if (result) {return true;}
1727         else goto updateState_exit_change_failed;
1728     }
1729
1730     // from ePS_WaitingForStreamEnable we can go to:
1731     //   - ePS_DryRunning if something went wrong while waiting
1732     //   - ePS_Running if the stream enabled correctly
1733     if (m_state == ePS_WaitingForStreamEnable) {
1734         if((next_state != ePS_DryRunning) &&
1735            (next_state != ePS_Running)) {
1736             goto updateState_exit_with_error;
1737         }
1738         if (next_state == ePS_DryRunning) {
1739             result = doDryRunning();
1740         } else {
1741             result = doRunning();
1742         }
1743         if (result) {return true;}
1744         else goto updateState_exit_change_failed;
1745     }
1746
1747     // from ePS_Running we can only start waiting for a disabled stream
1748     if (m_state == ePS_Running) {
1749         if(next_state != ePS_WaitingForStreamDisable) {
1750             goto updateState_exit_with_error;
1751         }
1752         result = doWaitForStreamDisable();
1753         if (result) {return true;}
1754         else goto updateState_exit_change_failed;
1755     }
1756
1757     // from ePS_WaitingForStreamDisable we can go to DryRunning
1758     if (m_state == ePS_WaitingForStreamDisable) {
1759         if(next_state != ePS_DryRunning) {
1760             goto updateState_exit_with_error;
1761         }
1762         result = doDryRunning();
1763         if (result) {return true;}
1764         else goto updateState_exit_change_failed;
1765     }
1766
1767     // if we arrive here there is an error
1768 updateState_exit_with_error:
1769     debugError("Invalid state transition: %s => %s\n",
1770         ePSToString(m_state), ePSToString(next_state));
1771     SIGNAL_ACTIVITY_ALL;
1772     return false;
1773 updateState_exit_change_failed:
1774     debugError("State transition failed: %s => %s\n",
1775         ePSToString(m_state), ePSToString(next_state));
1776     SIGNAL_ACTIVITY_ALL;
1777     return false;
1778 }
1779
1780 bool StreamProcessor::canProducePacket()
1781 {
1782     return canProduce(getNominalFramesPerPacket());
1783 }
1784 bool StreamProcessor::canProducePeriod()
1785 {
1786     return canProduce(m_StreamProcessorManager.getPeriodSize());
1787 }
1788 bool StreamProcessor::canProduce(unsigned int nframes)
1789 {
1790     if(m_in_xrun) return true;
1791     if(m_state == ePS_Running && m_next_state == ePS_Running) {
1792         // can we put a certain amount of frames into the buffer?
1793         unsigned int bufferspace = m_data_buffer->getBufferSpace();
1794         if(bufferspace >= nframes) {
1795             return true;
1796         } else return false;
1797     } else {
1798         if(getType() == ePT_Transmit) {
1799             // if we are an xmit SP, we cannot accept frames
1800             // when not running
1801             return false;
1802         } else {
1803             // if we are a receive SP, we can always accept frames
1804             // when not running
1805             return true;
1806         }
1807     }
1808 }
1809
1810 bool StreamProcessor::canConsumePacket()
1811 {
1812     return canConsume(getNominalFramesPerPacket());
1813 }
1814 bool StreamProcessor::canConsumePeriod()
1815 {
1816     return canConsume(m_StreamProcessorManager.getPeriodSize());
1817 }
1818 bool StreamProcessor::canConsume(unsigned int nframes)
1819 {
1820     if(m_in_xrun) return true;
1821     if(m_state == ePS_Running && m_next_state == ePS_Running) {
1822         // check whether we already fullfil the criterion
1823         unsigned int bufferfill = m_data_buffer->getBufferFill();
1824         if(bufferfill >= nframes) {
1825             return true;
1826         } else return false;
1827     } else {
1828         if(getType() == ePT_Transmit) {
1829             // if we are an xmit SP, and we're not running,
1830             // we can always provide frames
1831             return true;
1832         } else {
1833             // if we are a receive SP, we can't provide frames
1834             // when not running
1835             return false;
1836         }
1837     }
1838 }
1839
1840 /***********************************************
1841  * Helper routines                             *
1842  ***********************************************/
1843 // FIXME: I think this can be removed and replaced by putSilenceFrames
1844 bool
1845 StreamProcessor::transferSilence(unsigned int nframes)
1846 {
1847     bool retval;
1848
1849     #ifdef DEBUG
1850     signed int fc;
1851     ffado_timestamp_t ts_tail_tmp;
1852     m_data_buffer->getBufferTailTimestamp(&ts_tail_tmp, &fc);
1853     if (fc != 0) {
1854         debugWarning("Prefilling a buffer that already contains %d frames\n", fc);
1855     }
1856     #endif
1857
1858     // prepare a buffer of silence
1859     char *dummybuffer = (char *)calloc(getEventSize(), nframes * getEventsPerFrame());
1860     transmitSilenceBlock(dummybuffer, nframes, 0);
1861
1862     // add the silence data to the ringbuffer
1863     if(m_data_buffer->preloadFrames(nframes, dummybuffer, true)) {
1864         retval = true;
1865     } else {
1866         debugWarning("Could not write to event buffer\n");
1867         retval = false;
1868     }
1869
1870     free(dummybuffer);
1871     return retval;
1872 }
1873
1874 /**
1875  * @brief convert a eProcessorState to a string
1876  * @param s the state
1877  * @return a char * describing the state
1878  */
1879 const char *
1880 StreamProcessor::ePSToString(enum eProcessorState s) {
1881     switch (s) {
1882         case ePS_Invalid: return "ePS_Invalid";
1883         case ePS_Created: return "ePS_Created";
1884         case ePS_Stopped: return "ePS_Stopped";
1885         case ePS_WaitingForStream: return "ePS_WaitingForStream";
1886         case ePS_DryRunning: return "ePS_DryRunning";
1887         case ePS_WaitingForStreamEnable: return "ePS_WaitingForStreamEnable";
1888         case ePS_Running: return "ePS_Running";
1889         case ePS_WaitingForStreamDisable: return "ePS_WaitingForStreamDisable";
1890         case ePS_Error: return "ePS_Error";
1891         default: return "error: unknown state";
1892     }
1893 }
1894
1895 /**
1896  * @brief convert a eProcessorType to a string
1897  * @param t the type
1898  * @return a char * describing the state
1899  */
1900 const char *
1901 StreamProcessor::ePTToString(enum eProcessorType t) {
1902     switch (t) {
1903         case ePT_Receive: return "Receive";
1904         case ePT_Transmit: return "Transmit";
1905         default: return "error: unknown type";
1906     }
1907 }
1908
1909 /***********************************************
1910  * Debug                                       *
1911  ***********************************************/
1912 void
1913 StreamProcessor::dumpInfo()
1914 {
1915     #ifdef DEBUG
1916     debugOutputShort( DEBUG_LEVEL_NORMAL, " StreamProcessor %p, %s:\n", this, ePTToString(m_processor_type));
1917     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Port, Channel    : %d, %d\n", m_1394service.getPort(), m_channel);
1918     IsoHandler *h = m_IsoHandlerManager.getHandlerForStream(this);
1919     if (h) {
1920         debugOutputShort( DEBUG_LEVEL_NORMAL, "  Packets, Dropped, Skipped : %d, %d, %d\n",
1921                                               h->m_packets, h->m_dropped, h->m_skipped);
1922     } else {
1923         debugError("No handler for stream??\n");
1924     }
1925     uint64_t now = m_1394service.getCycleTimerTicks();
1926     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Now                   : %011llu (%03us %04uc %04ut)\n",
1927                         now,
1928                         (unsigned int)TICKS_TO_SECS(now),
1929                         (unsigned int)TICKS_TO_CYCLES(now),
1930                         (unsigned int)TICKS_TO_OFFSET(now));
1931     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Xrun?                 : %s\n", (m_in_xrun ? "True":"False"));
1932     if (m_state == m_next_state) {
1933         debugOutputShort( DEBUG_LEVEL_NORMAL, "  State                 : %s\n",
1934                                             ePSToString(m_state));
1935     } else {
1936         debugOutputShort( DEBUG_LEVEL_NORMAL, "  State                 : %s (Next: %s)\n",
1937                                               ePSToString(m_state), ePSToString(m_next_state));
1938         debugOutputShort( DEBUG_LEVEL_NORMAL, "    transition at       : %u\n", m_cycle_to_switch_state);
1939     }
1940     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Buffer                : %p\n", m_data_buffer);
1941     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Framerate             : Nominal: %u, Sync: %f, Buffer %f\n",
1942                                           m_StreamProcessorManager.getNominalRate(),
1943                                           24576000.0/m_StreamProcessorManager.getSyncSource().m_data_buffer->getRate(),
1944                                           24576000.0/m_data_buffer->getRate());
1945     float d = getSyncDelay();
1946     debugOutputShort(DEBUG_LEVEL_NORMAL, "  Sync delay             : %f ticks (%f frames, %f cy)\n",
1947                                          d, d/getTicksPerFrame(),
1948                                          d/((float)TICKS_PER_CYCLE));
1949     #endif
1950     m_data_buffer->dumpInfo();
1951 }
1952
1953 void
1954 StreamProcessor::printBufferInfo()
1955 {
1956     debugOutput(DEBUG_LEVEL_NORMAL,
1957                 "(%p, %8s) fc: %d fill: %u\n",
1958                 this, getTypeString(), m_data_buffer->getFrameCounter(), m_data_buffer->getBufferFill() );
1959 }
1960
1961 void
1962 StreamProcessor::setVerboseLevel(int l) {
1963     setDebugLevel(l);
1964     PortManager::setVerboseLevel(l);
1965     m_data_buffer->setVerboseLevel(l);
1966     debugOutput( DEBUG_LEVEL_VERBOSE, "Setting verbose level to %d...\n", l );
1967 }
1968
1969 } // end of namespace
Note: See TracBrowser for help on using the browser.