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

Revision 1525, 73.9 kB (checked in by ppalmers, 12 years ago)

- Allow to specify the DLL bandwidths for the CycleTimerHelper? and the TimestampedBuffer? in absolute units (Hz). This ensures samplerate-independent operation
- Reduce the default DLL bandwidth for the TimestampedBuffer?'s. This improves timestamp timing with a factor 10x, which should benefit especially the timing sensitive devices (MOTU).
- Allow to specify the DLL bandwith and other transmit settings through the configuration file
- Implement a sanity check for the instantanous samplerate to detect bogus timestamp processing

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