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

Revision 1271, 68.1 kB (checked in by ppalmers, 16 years ago)

fix extreme debugging

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