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

Revision 1536, 73.3 kB (checked in by ppalmers, 15 years ago)

introduce transmit prebuffering to increase reliability

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