root/trunk/libffado/src/libieee1394/IsoHandlerManager.cpp

Revision 2171, 70.6 kB (checked in by jwoithe, 12 years ago)

A second pass at addressing ticket #242. Define a global clock source within the SystemTimeSource? object and use this whenever clock_gettime() is called. On systems which support the new raw1394_read_cycle_timer_and_clock() libraw1394 call and CLOCK_MONOTONIC_RAW, these changes should ensure that all timing-sensitive parts of FFADO are using the same clock source. System tests under tests/systemtests/ have not been converted to use this new framework because they exist for different purposes and are not using the FFADO streaming infrastructure.

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 "IsoHandlerManager.h"
27 #include "ieee1394service.h"
28 #include "cycletimer.h"
29 #include "libstreaming/generic/StreamProcessor.h"
30
31 #include "libutil/Atomic.h"
32 #include "libutil/PosixThread.h"
33 #include "libutil/SystemTimeSource.h"
34 #include "libutil/Watchdog.h"
35 #include "libutil/Configuration.h"
36
37 #include <cstring>
38 #include <unistd.h>
39 #include <assert.h>
40
41 IMPL_DEBUG_MODULE( IsoHandlerManager, IsoHandlerManager, DEBUG_LEVEL_NORMAL );
42 IMPL_DEBUG_MODULE( IsoHandlerManager::IsoTask, IsoTask, DEBUG_LEVEL_NORMAL );
43 IMPL_DEBUG_MODULE( IsoHandlerManager::IsoHandler, IsoHandler, DEBUG_LEVEL_NORMAL );
44
45 using namespace Streaming;
46
47 // --- ISO Thread --- //
48
49 IsoHandlerManager::IsoTask::IsoTask(IsoHandlerManager& manager, enum IsoHandler::EHandlerType t)
50     : m_manager( manager )
51     , m_SyncIsoHandler ( NULL )
52     , m_handlerType( t )
53     , m_running( false )
54     , m_in_busreset( false )
55     , m_activity_wait_timeout_nsec (ISOHANDLERMANAGER_ISO_TASK_WAIT_TIMEOUT_USECS * 1000LL)
56 {
57 }
58
59 IsoHandlerManager::IsoTask::~IsoTask()
60 {
61     sem_destroy(&m_activity_semaphore);
62 }
63
64 bool
65 IsoHandlerManager::IsoTask::Init()
66 {
67     request_update = 0;
68
69     int i;
70     for (i=0; i < ISOHANDLERMANAGER_MAX_ISO_HANDLERS_PER_PORT; i++) {
71         m_IsoHandler_map_shadow[i] = NULL;
72         m_poll_fds_shadow[i].events = 0;
73     }
74     m_poll_nfds_shadow = 0;
75
76     #ifdef DEBUG
77     m_last_loop_entry = 0;
78     m_successive_short_loops = 0;
79     #endif
80
81     sem_init(&m_activity_semaphore, 0, 0);
82     m_running = true;
83     return true;
84 }
85
86 void
87 IsoHandlerManager::IsoTask::requestShadowMapUpdate()
88 {
89     debugOutput(DEBUG_LEVEL_VERBOSE, "(%p) enter\n", this);
90     INC_ATOMIC(&request_update);
91
92     // get the thread going again
93     signalActivity();
94     debugOutput(DEBUG_LEVEL_VERBOSE, "(%p) exit\n", this);
95 }
96
97 bool
98 IsoHandlerManager::IsoTask::handleBusReset()
99 {
100     bool retval = true;
101     if(!m_running) {
102         // nothing to do here
103         return true;
104     }
105     m_in_busreset = true;
106     requestShadowMapUpdate();
107
108     unsigned int i, max;
109     max = m_manager.m_IsoHandlers.size();
110     for (i = 0; i < max; i++) {
111         IsoHandler *h = m_manager.m_IsoHandlers.at(i);
112         assert(h);
113
114         // skip the handlers not intended for us
115         if(h->getType() != m_handlerType) continue;
116
117         if (!h->handleBusReset()) {
118             debugWarning("Failed to handle busreset on %p\n", h);
119             retval = false;
120         }
121     }
122
123     // re-enable processing
124     m_in_busreset = false;
125     requestShadowMapUpdate();
126     return retval;
127 }
128
129 // updates the internal stream map
130 // note that this should be executed with the guarantee that
131 // nobody will modify the parent data structures
132 void
133 IsoHandlerManager::IsoTask::updateShadowMapHelper()
134 {
135     debugOutput( DEBUG_LEVEL_VERBOSE, "(%p) updating shadow vars...\n", this);
136     // we are handling a busreset
137     if(m_in_busreset) {
138         m_poll_nfds_shadow = 0;
139         return;
140     }
141     unsigned int i, cnt, max;
142     max = m_manager.m_IsoHandlers.size();
143     m_SyncIsoHandler = NULL;
144     for (i = 0, cnt = 0; i < max; i++) {
145
146         // FIXME: This is a very crude guard against some other thread
147         // deleting handlers while this function is running.  While this
148         // didn't tend to happen with the old kernel firewire stack, delays
149         // in shutdown experienced in the new stack mean it can happen that
150         // a handler disappears during the running of this function.  This
151         // test should prevent "out of range" exceptions in most cases.
152         // However, it is racy: if the deletion happens between this
153         // conditional and the following at() call, an out of range
154         // condition can still happen.
155         if (i>=m_manager.m_IsoHandlers.size())
156             continue;
157
158         IsoHandler *h = m_manager.m_IsoHandlers.at(i);
159         assert(h);
160
161         // skip the handlers not intended for us
162         if(h->getType() != m_handlerType) continue;
163
164         // update the state of the handler
165         // FIXME: maybe this is not the best place to do this
166         // it might be better to eliminate the 'requestShadowMapUpdate'
167         // entirely and replace it with a mechanism that implements all
168         // actions on the m_manager.m_IsoHandlers in the loop
169         h->updateState();
170
171         // rebuild the map
172         if (h->isEnabled()) {
173             m_IsoHandler_map_shadow[cnt] = h;
174             m_poll_fds_shadow[cnt].fd = h->getFileDescriptor();
175             m_poll_fds_shadow[cnt].revents = 0;
176             m_poll_fds_shadow[cnt].events = POLLIN;
177             cnt++;
178             // FIXME: need a more generic approach here
179             if(   m_SyncIsoHandler == NULL
180                && h->getType() == IsoHandler::eHT_Transmit) {
181                 m_SyncIsoHandler = h;
182             }
183
184             debugOutput( DEBUG_LEVEL_VERBOSE, "(%p) %s handler %p added\n",
185                                               this, h->getTypeString(), h);
186         } else {
187             debugOutput( DEBUG_LEVEL_VERBOSE, "(%p) %s handler %p skipped (disabled)\n",
188                                               this, h->getTypeString(), h);
189         }
190         if(cnt > ISOHANDLERMANAGER_MAX_ISO_HANDLERS_PER_PORT) {
191             debugWarning("Too much ISO Handlers in thread...\n");
192             break;
193         }
194     }
195
196     // FIXME: need a more generic approach here
197     // if there are no active transmit handlers,
198     // use the first receive handler
199     if(   m_SyncIsoHandler == NULL
200        && m_poll_nfds_shadow) {
201         m_SyncIsoHandler = m_IsoHandler_map_shadow[0];
202     }
203     m_poll_nfds_shadow = cnt;
204     debugOutput( DEBUG_LEVEL_VERBOSE, "(%p) updated shadow vars...\n", this);
205 }
206
207 bool
208 IsoHandlerManager::IsoTask::Execute()
209 {
210     debugOutput(DEBUG_LEVEL_ULTRA_VERBOSE,
211                 "(%p, %s) Execute\n",
212                 this, (m_handlerType == IsoHandler::eHT_Transmit? "Transmit": "Receive"));
213     int err;
214     unsigned int i;
215     unsigned int m_poll_timeout = 10;
216
217     #ifdef DEBUG
218     uint64_t now = Util::SystemTimeSource::getCurrentTimeAsUsecs();
219     int diff = now - m_last_loop_entry;
220     if(diff < 100) {
221         debugOutputExtreme(DEBUG_LEVEL_VERY_VERBOSE,
222                            "(%p, %s) short loop detected (%d usec), cnt: %d\n",
223                            this, (m_handlerType == IsoHandler::eHT_Transmit? "Transmit": "Receive"),
224                            diff, m_successive_short_loops);
225         m_successive_short_loops++;
226         if(m_successive_short_loops > 10000) {
227             debugError("Shutting down runaway thread\n");
228             m_running = false;
229             return false;
230         }
231     } else {
232         // reset the counter
233         m_successive_short_loops = 0;
234     }
235     m_last_loop_entry = now;
236     #endif
237
238     // if some other thread requested a shadow map update, do it
239     if(request_update) {
240         updateShadowMapHelper();
241         DEC_ATOMIC(&request_update); // ack the update
242         assert(request_update >= 0);
243     }
244
245     // bypass if no handlers are registered
246     if (m_poll_nfds_shadow == 0) {
247         debugOutputExtreme(DEBUG_LEVEL_VERY_VERBOSE,
248                            "(%p, %s) bypass iterate since no handlers to poll\n",
249                            this, (m_handlerType == IsoHandler::eHT_Transmit? "Transmit": "Receive"));
250         usleep(m_poll_timeout * 1000);
251         return true;
252     }
253
254     // FIXME: what can happen is that poll() returns, but not all clients are
255     // ready. there might be some busy waiting behavior that still has to be solved.
256
257     // setup the poll here
258     // we should prevent a poll() where no events are specified, since that will only time-out
259     bool no_one_to_poll = true;
260     while(no_one_to_poll) {
261         for (i = 0; i < m_poll_nfds_shadow; i++) {
262             short events = 0;
263             IsoHandler *h = m_IsoHandler_map_shadow[i];
264             // we should only poll on a transmit handler
265             // that has a client that is ready to send
266             // something. Otherwise it will end up in
267             // busy wait looping since the packet function
268             // will defer processing (also avoids the
269             // AGAIN problem)
270             if (h->canIterateClient()) {
271                 events = POLLIN | POLLPRI;
272                 no_one_to_poll = false;
273             }
274             m_poll_fds_shadow[i].events = events;
275         }
276
277         if(no_one_to_poll) {
278             debugOutputExtreme(DEBUG_LEVEL_VERBOSE,
279                         "(%p, %s) No one to poll, waiting for something to happen\n",
280                         this, (m_handlerType == IsoHandler::eHT_Transmit? "Transmit": "Receive"));
281             // wait for something to happen
282             switch(waitForActivity()) {
283                 case IsoHandlerManager::IsoTask::eAR_Error:
284                     debugError("Error while waiting for activity\n");
285                     return false;
286                 case IsoHandlerManager::IsoTask::eAR_Interrupted:
287                     // FIXME: what to do here?
288                     debugWarning("Interrupted while waiting for activity\n");
289                     break;
290                 case IsoHandlerManager::IsoTask::eAR_Timeout:
291                     // FIXME: what to do here?
292                     debugWarning("Timeout while waiting for activity\n");
293                     no_one_to_poll = false; // exit the loop to be able to detect failing handlers
294                     break;
295                 case IsoHandlerManager::IsoTask::eAR_Activity:
296                     // do nothing
297                     debugOutputExtreme(DEBUG_LEVEL_VERBOSE,
298                                        "(%p, %s) something happened\n",
299                                        this, (m_handlerType == IsoHandler::eHT_Transmit? "Transmit": "Receive"));
300                     break;
301             }
302         }
303     }
304
305     // Use a shadow map of the fd's such that we don't have to update
306     // the fd map everytime we run poll().
307     err = poll (m_poll_fds_shadow, m_poll_nfds_shadow, m_poll_timeout);
308     uint32_t ctr_at_poll_return = m_manager.get1394Service().getCycleTimer();
309
310     if (err < 0) {
311         if (errno == EINTR) {
312             debugOutput(DEBUG_LEVEL_VERBOSE, "Ignoring poll return due to signal\n");
313             return true;
314         }
315         debugFatal("poll error: %s\n", strerror (errno));
316         m_running = false;
317         return false;
318     }
319
320     // find handlers that have died
321     uint64_t ctr_at_poll_return_ticks = CYCLE_TIMER_TO_TICKS(ctr_at_poll_return);
322     bool handler_died = false;
323     for (i = 0; i < m_poll_nfds_shadow; i++) {
324         // figure out if a handler has died
325
326         // this is the time of the last packet we saw in the iterate() handler
327         uint32_t last_packet_seen = m_IsoHandler_map_shadow[i]->getLastPacketTime();
328         if (last_packet_seen == 0xFFFFFFFF) {
329             // this was not iterated yet, so can't be dead
330             debugOutput(DEBUG_LEVEL_VERY_VERBOSE,
331                         "(%p, %s) handler %d didn't see any packets yet\n",
332                         this, (m_handlerType == IsoHandler::eHT_Transmit? "Transmit": "Receive"), i);
333             continue;
334         }
335
336         uint64_t last_packet_seen_ticks = CYCLE_TIMER_TO_TICKS(last_packet_seen);
337         // we use a relatively large value to distinguish between "death" and xrun
338         int64_t max_diff_ticks = TICKS_PER_SECOND * 2;
339         int64_t measured_diff_ticks = diffTicks(ctr_at_poll_return_ticks, last_packet_seen_ticks);
340
341         debugOutputExtreme(DEBUG_LEVEL_VERBOSE,
342                            "(%p, %s) check handler %d: diff = %"PRId64", max = %"PRId64", now: %08X, last: %08X\n",
343                            this, (m_handlerType == IsoHandler::eHT_Transmit? "Transmit": "Receive"),
344                            i, measured_diff_ticks, max_diff_ticks, ctr_at_poll_return, last_packet_seen);
345         if(measured_diff_ticks > max_diff_ticks) {
346             debugFatal("(%p, %s) Handler died: now: %08X, last: %08X, diff: %"PRId64" (max: %"PRId64")\n",
347                        this, (m_handlerType == IsoHandler::eHT_Transmit? "Transmit": "Receive"),
348                        ctr_at_poll_return, last_packet_seen, measured_diff_ticks, max_diff_ticks);
349             m_IsoHandler_map_shadow[i]->notifyOfDeath();
350             handler_died = true;
351         }
352     }
353
354     if(handler_died) {
355         m_running = false;
356         return false; // one or more handlers have died
357     }
358
359     // iterate the handlers
360     for (i = 0; i < m_poll_nfds_shadow; i++) {
361         #ifdef DEBUG
362         if(m_poll_fds_shadow[i].revents) {
363             debugOutputExtreme(DEBUG_LEVEL_VERBOSE,
364                         "(%p, %s) received events: %08X for (%d/%d, %p, %s)\n",
365                         this, (m_handlerType == IsoHandler::eHT_Transmit? "Transmit": "Receive"),
366                         m_poll_fds_shadow[i].revents,
367                         i, m_poll_nfds_shadow,
368                         m_IsoHandler_map_shadow[i],
369                         m_IsoHandler_map_shadow[i]->getTypeString());
370         }
371         #endif
372
373         // if we get here, it means two things:
374         // 1) the kernel can accept or provide packets (poll returned POLLIN)
375         // 2) the client can provide or accept packets (since we enabled polling)
376         if(m_poll_fds_shadow[i].revents & (POLLIN)) {
377             m_IsoHandler_map_shadow[i]->iterate(ctr_at_poll_return);
378         } else {
379             // there might be some error condition
380             if (m_poll_fds_shadow[i].revents & POLLERR) {
381                 debugWarning("(%p) error on fd for %d\n", this, i);
382             }
383             if (m_poll_fds_shadow[i].revents & POLLHUP) {
384                 debugWarning("(%p) hangup on fd for %d\n", this, i);
385             }
386         }
387     }
388     return true;
389 }
390
391 enum IsoHandlerManager::IsoTask::eActivityResult
392 IsoHandlerManager::IsoTask::waitForActivity()
393 {
394     debugOutputExtreme(DEBUG_LEVEL_VERBOSE,
395                        "(%p, %s) waiting for activity\n",
396                        this, (m_handlerType == IsoHandler::eHT_Transmit? "Transmit": "Receive"));
397     struct timespec ts;
398     int result;
399
400     if (Util::SystemTimeSource::clockGettime(&ts) == -1) {
401         debugError("clock_gettime failed\n");
402         return eAR_Error;
403     }
404
405     ts.tv_nsec += m_activity_wait_timeout_nsec;
406     while(ts.tv_nsec >= 1000000000LL) {
407         ts.tv_sec += 1;
408         ts.tv_nsec -= 1000000000LL;
409     }
410
411     result = sem_timedwait(&m_activity_semaphore, &ts);
412
413     if(result != 0) {
414         if (errno == ETIMEDOUT) {
415             debugOutput(DEBUG_LEVEL_VERBOSE,
416                         "(%p) sem_timedwait() timed out (result=%d)\n",
417                         this, result);
418             return eAR_Timeout;
419         } else if (errno == EINTR) {
420             debugOutput(DEBUG_LEVEL_VERBOSE,
421                         "(%p) sem_timedwait() interrupted by signal (result=%d)\n",
422                         this, result);
423             return eAR_Interrupted;
424         } else if (errno == EINVAL) {
425             debugError("(%p) sem_timedwait error (result=%d errno=EINVAL)\n",
426                         this, result);
427             debugError("(%p) timeout_nsec=%lld ts.sec=%"PRId64" ts.nsec=%"PRId64"\n",
428                        this, m_activity_wait_timeout_nsec,
429                        (int64_t)ts.tv_sec, (int64_t)ts.tv_nsec);
430             return eAR_Error;
431         } else {
432             debugError("(%p) sem_timedwait error (result=%d errno=%d)\n",
433                         this, result, errno);
434             debugError("(%p) timeout_nsec=%lld ts.sec=%"PRId64" ts.nsec=%"PRId64"\n",
435                        this, m_activity_wait_timeout_nsec,
436                        (int64_t)ts.tv_sec, (int64_t)ts.tv_nsec);
437             return eAR_Error;
438         }
439     }
440
441     debugOutput(DEBUG_LEVEL_ULTRA_VERBOSE,
442                 "(%p, %s) got activity\n",
443                 this, (m_handlerType == IsoHandler::eHT_Transmit? "Transmit": "Receive"));
444     return eAR_Activity;
445 }
446
447 void
448 IsoHandlerManager::IsoTask::signalActivity()
449 {
450     // signal the activity cond var
451     sem_post(&m_activity_semaphore);
452     debugOutput(DEBUG_LEVEL_ULTRA_VERBOSE,
453                 "(%p, %s) activity\n",
454                 this, (m_handlerType == IsoHandler::eHT_Transmit? "Transmit": "Receive"));
455 }
456
457 void IsoHandlerManager::IsoTask::setVerboseLevel(int i) {
458     setDebugLevel(i);
459     debugOutput( DEBUG_LEVEL_VERBOSE, "Setting verbose level to %d...\n", i );
460 }
461
462 // -- the ISO handler manager -- //
463 IsoHandlerManager::IsoHandlerManager(Ieee1394Service& service)
464    : m_State(E_Created)
465    , m_service( service )
466    , m_realtime(false), m_priority(0)
467    , m_IsoThreadTransmit ( NULL )
468    , m_IsoTaskTransmit ( NULL )
469    , m_IsoThreadReceive ( NULL )
470    , m_IsoTaskReceive ( NULL )
471 {
472 }
473
474 IsoHandlerManager::IsoHandlerManager(Ieee1394Service& service, bool run_rt, int rt_prio)
475    : m_State(E_Created)
476    , m_service( service )
477    , m_realtime(run_rt), m_priority(rt_prio)
478    , m_IsoThreadTransmit ( NULL )
479    , m_IsoTaskTransmit ( NULL )
480    , m_IsoThreadReceive ( NULL )
481    , m_IsoTaskReceive ( NULL )
482    , m_MissedCyclesOK ( false )
483 {
484 }
485
486 IsoHandlerManager::~IsoHandlerManager()
487 {
488     stopHandlers();
489     pruneHandlers();
490     if(m_IsoHandlers.size() > 0) {
491         debugError("Still some handlers in use\n");
492     }
493     if (m_IsoThreadTransmit) {
494         m_IsoThreadTransmit->Stop();
495         delete m_IsoThreadTransmit;
496     }
497     if (m_IsoThreadReceive) {
498         m_IsoThreadReceive->Stop();
499         delete m_IsoThreadReceive;
500     }
501     if (m_IsoTaskTransmit) {
502         delete m_IsoTaskTransmit;
503     }
504     if (m_IsoTaskReceive) {
505         delete m_IsoTaskReceive;
506     }
507 }
508
509 bool
510 IsoHandlerManager::handleBusReset()
511 {
512     debugOutput( DEBUG_LEVEL_NORMAL, "bus reset...\n");
513     // A few things can happen on bus reset:
514     // 1) no devices added/removed => streams are still valid, but might have to be restarted
515     // 2) a device was removed => some streams become invalid
516     // 3) a device was added => same as 1, new device is ignored
517     if (!m_IsoTaskTransmit) {
518         debugError("No xmit task\n");
519         return false;
520     }
521     if (!m_IsoTaskReceive) {
522         debugError("No receive task\n");
523         return false;
524     }
525     if (!m_IsoTaskTransmit->handleBusReset()) {
526         debugWarning("could no handle busreset on xmit\n");
527     }
528     if (!m_IsoTaskReceive->handleBusReset()) {
529         debugWarning("could no handle busreset on recv\n");
530     }
531     return true;
532 }
533
534 void
535 IsoHandlerManager::requestShadowMapUpdate()
536 {
537     if(m_IsoTaskTransmit) m_IsoTaskTransmit->requestShadowMapUpdate();
538     if(m_IsoTaskReceive) m_IsoTaskReceive->requestShadowMapUpdate();
539 }
540
541 bool
542 IsoHandlerManager::setThreadParameters(bool rt, int priority) {
543     debugOutput( DEBUG_LEVEL_VERBOSE, "(%p) switch to: (rt=%d, prio=%d)...\n", this, rt, priority);
544     if (priority > THREAD_MAX_RTPRIO) priority = THREAD_MAX_RTPRIO; // cap the priority
545     if (priority < THREAD_MIN_RTPRIO) priority = THREAD_MIN_RTPRIO; // cap the priority
546     m_realtime = rt;
547     m_priority = priority;
548
549     // grab the options from the parent
550     Util::Configuration *config = m_service.getConfiguration();
551     int ihm_iso_prio_increase = ISOHANDLERMANAGER_ISO_PRIO_INCREASE;
552     int ihm_iso_prio_increase_xmit = ISOHANDLERMANAGER_ISO_PRIO_INCREASE_XMIT;
553     int ihm_iso_prio_increase_recv = ISOHANDLERMANAGER_ISO_PRIO_INCREASE_RECV;
554     if(config) {
555         config->getValueForSetting("ieee1394.isomanager.prio_increase", ihm_iso_prio_increase);
556         config->getValueForSetting("ieee1394.isomanager.prio_increase_xmit", ihm_iso_prio_increase_xmit);
557         config->getValueForSetting("ieee1394.isomanager.prio_increase_recv", ihm_iso_prio_increase_recv);
558     }
559
560     if (m_IsoThreadTransmit) {
561         if (m_realtime) {
562             m_IsoThreadTransmit->AcquireRealTime(m_priority
563                                                  + ihm_iso_prio_increase
564                                                  + ihm_iso_prio_increase_xmit);
565         } else {
566             m_IsoThreadTransmit->DropRealTime();
567         }
568     }
569     if (m_IsoThreadReceive) {
570         if (m_realtime) {
571             m_IsoThreadReceive->AcquireRealTime(m_priority
572                                                 + ihm_iso_prio_increase
573                                                 + ihm_iso_prio_increase_recv);
574         } else {
575             m_IsoThreadReceive->DropRealTime();
576         }
577     }
578
579     return true;
580 }
581
582 bool IsoHandlerManager::init()
583 {
584     debugOutput( DEBUG_LEVEL_VERBOSE, "Initializing ISO manager %p...\n", this);
585     // check state
586     if(m_State != E_Created) {
587         debugError("Manager already initialized...\n");
588         return false;
589     }
590
591     // grab the options from the parent
592     Util::Configuration *config = m_service.getConfiguration();
593     int ihm_iso_prio_increase = ISOHANDLERMANAGER_ISO_PRIO_INCREASE;
594     int ihm_iso_prio_increase_xmit = ISOHANDLERMANAGER_ISO_PRIO_INCREASE_XMIT;
595     int ihm_iso_prio_increase_recv = ISOHANDLERMANAGER_ISO_PRIO_INCREASE_RECV;
596     int64_t isotask_activity_timeout_usecs = ISOHANDLERMANAGER_ISO_TASK_WAIT_TIMEOUT_USECS;
597     if(config) {
598         config->getValueForSetting("ieee1394.isomanager.prio_increase", ihm_iso_prio_increase);
599         config->getValueForSetting("ieee1394.isomanager.prio_increase_xmit", ihm_iso_prio_increase_xmit);
600         config->getValueForSetting("ieee1394.isomanager.prio_increase_recv", ihm_iso_prio_increase_recv);
601         config->getValueForSetting("ieee1394.isomanager.isotask_activity_timeout_usecs", isotask_activity_timeout_usecs);
602     }
603
604     // create threads to iterate our ISO handlers
605     debugOutput( DEBUG_LEVEL_VERBOSE, "Create iso thread for %p transmit...\n", this);
606     m_IsoTaskTransmit = new IsoTask( *this, IsoHandler::eHT_Transmit );
607     if(!m_IsoTaskTransmit) {
608         debugFatal("No task\n");
609         return false;
610     }
611     m_IsoTaskTransmit->setVerboseLevel(getDebugLevel());
612     m_IsoTaskTransmit->m_activity_wait_timeout_nsec = isotask_activity_timeout_usecs * 1000LL;
613     m_IsoThreadTransmit = new Util::PosixThread(m_IsoTaskTransmit, "ISOXMT", m_realtime,
614                                                 m_priority + ihm_iso_prio_increase
615                                                 + ihm_iso_prio_increase_xmit,
616                                                 PTHREAD_CANCEL_DEFERRED);
617
618     if(!m_IsoThreadTransmit) {
619         debugFatal("No thread\n");
620         return false;
621     }
622     m_IsoThreadTransmit->setVerboseLevel(getDebugLevel());
623
624     debugOutput( DEBUG_LEVEL_VERBOSE, "Create iso thread for %p receive...\n", this);
625     m_IsoTaskReceive = new IsoTask( *this, IsoHandler::eHT_Receive );
626     if(!m_IsoTaskReceive) {
627         debugFatal("No task\n");
628         return false;
629     }
630     m_IsoTaskReceive->setVerboseLevel(getDebugLevel());
631     m_IsoThreadReceive = new Util::PosixThread(m_IsoTaskReceive, "ISORCV", m_realtime,
632                                                m_priority + ihm_iso_prio_increase
633                                                + ihm_iso_prio_increase_recv,
634                                                PTHREAD_CANCEL_DEFERRED);
635
636     if(!m_IsoThreadReceive) {
637         debugFatal("No thread\n");
638         return false;
639     }
640     m_IsoThreadReceive->setVerboseLevel(getDebugLevel());
641     // register the thread with the RT watchdog
642     Util::Watchdog *watchdog = m_service.getWatchdog();
643     if(watchdog) {
644         if(!watchdog->registerThread(m_IsoThreadTransmit)) {
645             debugWarning("could not register iso transmit thread with watchdog\n");
646         }
647         if(!watchdog->registerThread(m_IsoThreadReceive)) {
648             debugWarning("could not register iso receive thread with watchdog\n");
649         }
650     } else {
651         debugWarning("could not find valid watchdog\n");
652     }
653
654     if (m_IsoThreadTransmit->Start() != 0) {
655         debugFatal("Could not start ISO Transmit thread\n");
656         return false;
657     }
658     if (m_IsoThreadReceive->Start() != 0) {
659         debugFatal("Could not start ISO Receive thread\n");
660         return false;
661     }
662
663     m_State=E_Running;
664     return true;
665 }
666
667 void
668 IsoHandlerManager::signalActivityTransmit()
669 {
670     assert(m_IsoTaskTransmit);
671     m_IsoTaskTransmit->signalActivity();
672 }
673
674 void
675 IsoHandlerManager::signalActivityReceive()
676 {
677     assert(m_IsoTaskReceive);
678     m_IsoTaskReceive->signalActivity();
679 }
680
681 bool IsoHandlerManager::registerHandler(IsoHandler *handler)
682 {
683     debugOutput( DEBUG_LEVEL_VERBOSE, "enter...\n");
684     assert(handler);
685     handler->setVerboseLevel(getDebugLevel());
686     m_IsoHandlers.push_back(handler);
687     requestShadowMapUpdate();
688     return true;
689 }
690
691 bool IsoHandlerManager::unregisterHandler(IsoHandler *handler)
692 {
693     debugOutput( DEBUG_LEVEL_VERBOSE, "enter...\n");
694     assert(handler);
695
696     for ( IsoHandlerVectorIterator it = m_IsoHandlers.begin();
697       it != m_IsoHandlers.end();
698       ++it )
699     {
700         if ( *it == handler ) {
701             m_IsoHandlers.erase(it);
702             requestShadowMapUpdate();
703             return true;
704         }
705     }
706     debugFatal("Could not find handler (%p)\n", handler);
707     return false; //not found
708 }
709
710 /**
711  * Registers an StreamProcessor with the IsoHandlerManager.
712  *
713  * If nescessary, an IsoHandler is created to handle this stream.
714  * Once an StreamProcessor is registered to the handler, it will be included
715  * in the ISO streaming cycle (i.e. receive/transmit of it will occur).
716  *
717  * @param stream the stream to register
718  * @return true if registration succeeds
719  *
720  * \todo : currently there is a one-to-one mapping
721  *        between streams and handlers, this is not ok for
722  *        multichannel receive
723  */
724 bool IsoHandlerManager::registerStream(StreamProcessor *stream)
725 {
726     debugOutput( DEBUG_LEVEL_VERBOSE, "Registering %s stream %p\n", stream->getTypeString(), stream);
727     assert(stream);
728
729     IsoHandler* h = NULL;
730
731     // make sure the stream isn't already attached to a handler
732     for ( IsoHandlerVectorIterator it = m_IsoHandlers.begin();
733       it != m_IsoHandlers.end();
734       ++it )
735     {
736         if((*it)->isStreamRegistered(stream)) {
737             debugError( "stream already registered!\n");
738             return false;
739         }
740     }
741
742     // clean up all handlers that aren't used
743     pruneHandlers();
744
745     // allocate a handler for this stream
746     if (stream->getType()==StreamProcessor::ePT_Receive) {
747         // grab the options from the parent
748         Util::Configuration *config = m_service.getConfiguration();
749         int receive_mode_setting = DEFAULT_ISO_RECEIVE_MODE;
750         int bufferfill_mode_threshold = BUFFERFILL_MODE_THRESHOLD;
751         int min_interrupts_per_period = MINIMUM_INTERRUPTS_PER_PERIOD;
752         int max_nb_buffers_recv = MAX_RECV_NB_BUFFERS;
753         int min_packetsize_recv = MIN_RECV_PACKET_SIZE;
754         if(config) {
755             config->getValueForSetting("ieee1394.isomanager.iso_receive_mode", receive_mode_setting);
756             config->getValueForSetting("ieee1394.isomanager.bufferfill_mode_threshold", bufferfill_mode_threshold);
757             config->getValueForSetting("ieee1394.isomanager.min_interrupts_per_period", min_interrupts_per_period);
758             config->getValueForSetting("ieee1394.isomanager.max_nb_buffers_recv", max_nb_buffers_recv);
759             config->getValueForSetting("ieee1394.isomanager.min_packetsize_recv", min_packetsize_recv);
760         }
761
762         // setup the optimal parameters for the raw1394 ISO buffering
763         unsigned int packets_per_period = stream->getPacketsPerPeriod();
764         // reserve space for the 1394 header too (might not be necessary)
765         unsigned int max_packet_size = stream->getMaxPacketSize() + 8;
766         unsigned int page_size = getpagesize();
767
768         enum raw1394_iso_dma_recv_mode receive_mode =
769                 RAW1394_DMA_PACKET_PER_BUFFER;
770         switch(receive_mode_setting) {
771             case 0:
772                 if(packets_per_period < (unsigned)bufferfill_mode_threshold) {
773                     debugOutput( DEBUG_LEVEL_VERBOSE, "Using packet-per-buffer mode (auto) [%d, %d]\n",
774                                  packets_per_period, bufferfill_mode_threshold);
775                     receive_mode = RAW1394_DMA_PACKET_PER_BUFFER;
776                 } else {
777                     debugOutput( DEBUG_LEVEL_VERBOSE, "Using bufferfill mode (auto) [%d, %d]\n",
778                                  packets_per_period, bufferfill_mode_threshold);
779                     receive_mode = RAW1394_DMA_BUFFERFILL;
780                 }
781                 break;
782             case 1:
783                 debugOutput( DEBUG_LEVEL_VERBOSE, "Using packet-per-buffer mode (config)\n");
784                 receive_mode = RAW1394_DMA_PACKET_PER_BUFFER;
785                 break;
786             case 2:
787                 debugOutput( DEBUG_LEVEL_VERBOSE, "Using bufferfill mode (config)\n");
788                 receive_mode = RAW1394_DMA_BUFFERFILL;
789                 break;
790             default: debugWarning("Bogus receive mode setting in config: %d\n", receive_mode_setting);
791         }
792
793         // Ensure we don't request a packet size bigger than the
794         // kernel-enforced maximum which is currently 1 page.
795         // NOTE: PP: this is not really true AFAICT
796         if (max_packet_size > page_size) {
797             debugError("max packet size (%u) > page size (%u)\n", max_packet_size, page_size);
798             return false;
799         }
800         if (max_packet_size < (unsigned)min_packetsize_recv) {
801             debugError("min packet size (%u) < MIN_RECV_PACKET_SIZE (%u), using min value\n",
802                        max_packet_size, min_packetsize_recv);
803             max_packet_size = min_packetsize_recv;
804         }
805
806         // apparently a too small value causes issues too
807         if(max_packet_size < 200) max_packet_size = 200;
808
809         // the interrupt/wakeup interval prediction of raw1394 is a mess...
810         int irq_interval = (packets_per_period-1) / min_interrupts_per_period;
811         if(irq_interval <= 0) irq_interval=1;
812
813         // the receive buffer size doesn't matter for the latency,
814         // it does seem to be confined to a certain region for correct
815         // operation. However it is not clear how many.
816         int buffers = max_nb_buffers_recv;
817
818         // ensure at least 2 hardware interrupts per ISO buffer wraparound
819         if(irq_interval > buffers/2) {
820             irq_interval = buffers/2;
821         }
822
823         // create the actual handler
824         debugOutput( DEBUG_LEVEL_VERBOSE, " creating IsoRecvHandler\n");
825         h = new IsoHandler(*this, IsoHandler::eHT_Receive,
826                            buffers, max_packet_size, irq_interval);
827
828         if(!h) {
829             debugFatal("Could not create IsoRecvHandler\n");
830             return false;
831         }
832
833         h->setReceiveMode(receive_mode);
834
835     } else if (stream->getType()==StreamProcessor::ePT_Transmit) {
836         // grab the options from the parent
837         Util::Configuration *config = m_service.getConfiguration();
838         int min_interrupts_per_period = MINIMUM_INTERRUPTS_PER_PERIOD;
839         int max_nb_buffers_xmit = MAX_XMIT_NB_BUFFERS;
840         int max_packetsize_xmit = MAX_XMIT_PACKET_SIZE;
841         int min_packetsize_xmit = MIN_XMIT_PACKET_SIZE;
842         if(config) {
843             config->getValueForSetting("ieee1394.isomanager.min_interrupts_per_period", min_interrupts_per_period);
844             config->getValueForSetting("ieee1394.isomanager.max_nb_buffers_xmit", max_nb_buffers_xmit);
845             config->getValueForSetting("ieee1394.isomanager.max_packetsize_xmit", max_packetsize_xmit);
846             config->getValueForSetting("ieee1394.isomanager.min_packetsize_xmit", min_packetsize_xmit);
847         }
848
849         // setup the optimal parameters for the raw1394 ISO buffering
850         // reserve space for the 1394 header too (might not be necessary)
851         unsigned int max_packet_size = stream->getMaxPacketSize() + 8;
852
853         if (max_packet_size > (unsigned)max_packetsize_xmit) {
854             debugError("max packet size (%u) > MAX_XMIT_PACKET_SIZE (%u)\n",
855                        max_packet_size, max_packetsize_xmit);
856             return false;
857         }
858         if (max_packet_size < (unsigned)min_packetsize_xmit) {
859             debugError("min packet size (%u) < MIN_XMIT_PACKET_SIZE (%u), using min value\n",
860                        max_packet_size, min_packetsize_xmit);
861             max_packet_size = min_packetsize_xmit;
862         }
863
864         int buffers = max_nb_buffers_xmit;
865         unsigned int packets_per_period = stream->getPacketsPerPeriod();
866
867         int irq_interval = (packets_per_period-1) / min_interrupts_per_period;
868         if(irq_interval <= 0) irq_interval=1;
869         // ensure at least 2 hardware interrupts per ISO buffer wraparound
870         if(irq_interval > buffers/2) {
871             irq_interval = buffers/2;
872         }
873
874         debugOutput( DEBUG_LEVEL_VERBOSE, " creating IsoXmitHandler\n");
875
876         // create the actual handler
877         h = new IsoHandler(*this, IsoHandler::eHT_Transmit,
878                            buffers, max_packet_size, irq_interval);
879
880         if(!h) {
881             debugFatal("Could not create IsoXmitHandler\n");
882             return false;
883         }
884
885     } else {
886         debugFatal("Bad stream type\n");
887         return false;
888     }
889
890     h->setVerboseLevel(getDebugLevel());
891
892     // register the stream with the handler
893     if(!h->registerStream(stream)) {
894         debugFatal("Could not register receive stream with handler\n");
895         return false;
896     }
897
898     // register the handler with the manager
899     if(!registerHandler(h)) {
900         debugFatal("Could not register receive handler with manager\n");
901         return false;
902     }
903     debugOutput( DEBUG_LEVEL_VERBOSE, " registered stream (%p) with handler (%p)\n", stream, h);
904
905     m_StreamProcessors.push_back(stream);
906     debugOutput( DEBUG_LEVEL_VERBOSE, " %zd streams, %zd handlers registered\n",
907                                       m_StreamProcessors.size(), m_IsoHandlers.size());
908     return true;
909 }
910
911 bool IsoHandlerManager::unregisterStream(StreamProcessor *stream)
912 {
913     debugOutput( DEBUG_LEVEL_VERBOSE, "Unregistering %s stream %p\n", stream->getTypeString(), stream);
914     assert(stream);
915
916     // make sure the stream isn't attached to a handler anymore
917     for ( IsoHandlerVectorIterator it = m_IsoHandlers.begin();
918       it != m_IsoHandlers.end();
919       ++it )
920     {
921         if((*it)->isStreamRegistered(stream)) {
922             if(!(*it)->unregisterStream(stream)) {
923                 debugOutput( DEBUG_LEVEL_VERBOSE, " could not unregister stream (%p) from handler (%p)...\n",stream,*it);
924                 return false;
925             }
926             debugOutput( DEBUG_LEVEL_VERBOSE, " unregistered stream (%p) from handler (%p)...\n",stream,*it);
927         }
928     }
929
930     // clean up all handlers that aren't used
931     pruneHandlers();
932
933     // remove the stream from the registered streams list
934     for ( StreamProcessorVectorIterator it = m_StreamProcessors.begin();
935       it != m_StreamProcessors.end();
936       ++it )
937     {
938         if ( *it == stream ) {
939             m_StreamProcessors.erase(it);
940             debugOutput( DEBUG_LEVEL_VERBOSE, " deleted stream (%p) from list...\n", *it);
941             return true;
942         }
943     }
944     return false; //not found
945 }
946
947 /**
948  * @brief unregister a handler from the manager
949  * @note called without the lock held.
950  */
951 void IsoHandlerManager::pruneHandlers() {
952     debugOutput( DEBUG_LEVEL_VERBOSE, "enter...\n");
953     IsoHandlerVector toUnregister;
954
955     // find all handlers that are not in use
956     for ( IsoHandlerVectorIterator it = m_IsoHandlers.begin();
957           it != m_IsoHandlers.end();
958           ++it )
959     {
960         if(!((*it)->inUse())) {
961             debugOutput( DEBUG_LEVEL_VERBOSE, " handler (%p) not in use\n",*it);
962             toUnregister.push_back(*it);
963         }
964     }
965     // delete them
966     for ( IsoHandlerVectorIterator it = toUnregister.begin();
967           it != toUnregister.end();
968           ++it )
969     {
970         unregisterHandler(*it);
971
972         debugOutput( DEBUG_LEVEL_VERBOSE, " deleting handler (%p)\n",*it);
973
974         // Now the handler's been unregistered it won't be reused
975         // again.  Therefore it really needs to be formally deleted
976         // to free up the raw1394 handle.  Otherwise things fall
977         // apart after several xrun recoveries as the system runs
978         // out of resources to support all the disused but still
979         // allocated raw1394 handles.  At least this is the current
980         // theory as to why we end up with "memory allocation"
981         // failures after several Xrun recoveries.
982         delete *it;
983     }
984 }
985
986 int
987 IsoHandlerManager::getPacketLatencyForStream(Streaming::StreamProcessor *stream) {
988     for ( IsoHandlerVectorIterator it = m_IsoHandlers.begin();
989       it != m_IsoHandlers.end();
990       ++it )
991     {
992         if((*it)->isStreamRegistered(stream)) {
993             return (*it)->getIrqInterval();
994         }
995     }
996     debugError("Stream %p has no attached handler\n", stream);
997     return 0;
998 }
999
1000 IsoHandlerManager::IsoHandler *
1001 IsoHandlerManager::getHandlerForStream(Streaming::StreamProcessor *stream) {
1002     for ( IsoHandlerVectorIterator it = m_IsoHandlers.begin();
1003       it != m_IsoHandlers.end();
1004       ++it )
1005     {
1006         if((*it)->isStreamRegistered(stream)) {
1007             return (*it);
1008         }
1009     }
1010     debugError("Stream %p has no attached handler\n", stream);
1011     return NULL;
1012 }
1013
1014 void
1015 IsoHandlerManager::dumpInfoForStream(Streaming::StreamProcessor *stream)
1016 {
1017     IsoHandler *h = getHandlerForStream(stream);
1018     if (h) {
1019         debugOutputShort( DEBUG_LEVEL_NORMAL, "  Packets, Dropped, Skipped : %d, %d, %d\n",
1020                             h->m_packets, h->m_dropped, h->m_skipped);
1021     } else {
1022         debugError("No handler for stream %p??\n", stream);
1023     }
1024 }
1025
1026 void IsoHandlerManager::setIsoStartCycleForStream(Streaming::StreamProcessor *stream, signed int cycle) {
1027     // Permit the direct manipulation of the m_switch_on_cycle field from
1028     // the stream's handler.  This is usually used to set it to -1 so the
1029     // kernel (at least with the ieee1394 stack) starts the streaming as
1030     // soon as possible, something that is required for some interfaces (eg:
1031     // RME).  Note that as of 20 Dec 2010 it seems that ordinarily
1032     // m_switch_on_cycle remains fixed at 0 (its initialised value) because
1033     // requestEnable() doesn't set it.  This allows the override configured
1034     // by this function to take effect.
1035     IsoHandler *h = getHandlerForStream(stream);
1036     h->setIsoStartCycle(cycle);
1037 }
1038
1039 bool
1040 IsoHandlerManager::startHandlerForStream(Streaming::StreamProcessor *stream) {
1041     return startHandlerForStream(stream, -1);
1042 }
1043
1044 bool
1045 IsoHandlerManager::startHandlerForStream(Streaming::StreamProcessor *stream, int cycle) {
1046     // check state
1047     if(m_State != E_Running) {
1048         debugError("Incorrect state, expected E_Running, got %s\n", eHSToString(m_State));
1049         return false;
1050     }
1051     for ( IsoHandlerVectorIterator it = m_IsoHandlers.begin();
1052       it != m_IsoHandlers.end();
1053       ++it )
1054     {
1055         if((*it)->isStreamRegistered(stream)) {
1056             debugOutput( DEBUG_LEVEL_VERBOSE, " starting handler %p for stream %p\n", *it, stream);
1057             if(!(*it)->requestEnable(cycle)) {
1058                 debugOutput( DEBUG_LEVEL_VERBOSE, " could not request enable for handler %p)\n",*it);
1059                 return false;
1060             }
1061
1062             if((*it)->getType() == IsoHandler::eHT_Transmit) {
1063                 m_IsoTaskTransmit->requestShadowMapUpdate();
1064             } else {
1065                 m_IsoTaskReceive->requestShadowMapUpdate();
1066             }
1067
1068             debugOutput(DEBUG_LEVEL_VERY_VERBOSE, " requested enable for handler %p\n", *it);
1069             return true;
1070         }
1071     }
1072     debugError("Stream %p has no attached handler\n", stream);
1073     return false;
1074 }
1075
1076 bool
1077 IsoHandlerManager::stopHandlerForStream(Streaming::StreamProcessor *stream) {
1078     // check state
1079     if(m_State != E_Running) {
1080         debugError("Incorrect state, expected E_Running, got %s\n", eHSToString(m_State));
1081         return false;
1082     }
1083     for ( IsoHandlerVectorIterator it = m_IsoHandlers.begin();
1084       it != m_IsoHandlers.end();
1085       ++it )
1086     {
1087         if((*it)->isStreamRegistered(stream)) {
1088             debugOutput( DEBUG_LEVEL_VERBOSE, " stopping handler %p for stream %p\n", *it, stream);
1089             if(!(*it)->requestDisable()) {
1090                 debugOutput( DEBUG_LEVEL_VERBOSE, " could not request disable for handler %p\n",*it);
1091                 return false;
1092             }
1093
1094             if((*it)->getType() == IsoHandler::eHT_Transmit) {
1095                 m_IsoTaskTransmit->requestShadowMapUpdate();
1096             } else {
1097                 m_IsoTaskReceive->requestShadowMapUpdate();
1098             }
1099
1100             debugOutput(DEBUG_LEVEL_VERBOSE, " requested disable for handler %p\n", *it);
1101             return true;
1102         }
1103     }
1104     debugError("Stream %p has no attached handler\n", stream);
1105     return false;
1106 }
1107
1108 bool IsoHandlerManager::stopHandlers() {
1109     debugOutput( DEBUG_LEVEL_VERBOSE, "enter...\n");
1110
1111     // check state
1112     if(m_State != E_Running) {
1113         debugError("Incorrect state, expected E_Running, got %s\n", eHSToString(m_State));
1114         return false;
1115     }
1116
1117     bool retval=true;
1118
1119     for ( IsoHandlerVectorIterator it = m_IsoHandlers.begin();
1120         it != m_IsoHandlers.end();
1121         ++it )
1122     {
1123         debugOutput( DEBUG_LEVEL_VERBOSE, "Stopping handler (%p)\n",*it);
1124
1125         if(!(*it)->requestDisable()) {
1126             debugOutput( DEBUG_LEVEL_VERBOSE, " could not request disable for handler %p\n",*it);
1127             return false;
1128         }
1129
1130         if((*it)->getType() == IsoHandler::eHT_Transmit) {
1131             m_IsoTaskTransmit->requestShadowMapUpdate();
1132         } else {
1133             m_IsoTaskReceive->requestShadowMapUpdate();
1134         }
1135
1136         debugOutput(DEBUG_LEVEL_VERBOSE, " requested disable for handler %p\n", *it);
1137     }
1138
1139     if (retval) {
1140         m_State=E_Prepared;
1141     } else {
1142         m_State=E_Error;
1143     }
1144     return retval;
1145 }
1146
1147 bool IsoHandlerManager::reset() {
1148     debugOutput( DEBUG_LEVEL_VERBOSE, "enter...\n");
1149     // check state
1150     if(m_State == E_Error) {
1151         debugFatal("Resetting from error condition not yet supported...\n");
1152         return false;
1153     }
1154     // if not in an error condition, reset means stop the handlers
1155     return stopHandlers();
1156 }
1157
1158 void IsoHandlerManager::setVerboseLevel(int i) {
1159     setDebugLevel(i);
1160     // propagate the debug level
1161     for ( IsoHandlerVectorIterator it = m_IsoHandlers.begin();
1162           it != m_IsoHandlers.end();
1163           ++it )
1164     {
1165         (*it)->setVerboseLevel(i);
1166     }
1167     if(m_IsoThreadTransmit) m_IsoThreadTransmit->setVerboseLevel(i);
1168     if(m_IsoTaskTransmit)   m_IsoTaskTransmit->setVerboseLevel(i);
1169     if(m_IsoThreadReceive)  m_IsoThreadReceive->setVerboseLevel(i);
1170     if(m_IsoTaskReceive)    m_IsoTaskReceive->setVerboseLevel(i);
1171     setDebugLevel(i);
1172     debugOutput( DEBUG_LEVEL_VERBOSE, "Setting verbose level to %d...\n", i );
1173 }
1174
1175 void IsoHandlerManager::dumpInfo() {
1176     #ifdef DEBUG
1177     unsigned int i=0;
1178     debugOutputShort( DEBUG_LEVEL_NORMAL, "Dumping IsoHandlerManager Stream handler information...\n");
1179     debugOutputShort( DEBUG_LEVEL_NORMAL, " State: %d\n",(int)m_State);
1180
1181     for ( IsoHandlerVectorIterator it = m_IsoHandlers.begin();
1182           it != m_IsoHandlers.end();
1183           ++it )
1184     {
1185         debugOutputShort( DEBUG_LEVEL_NORMAL, " IsoHandler %d (%p)\n",i++,*it);
1186         (*it)->dumpInfo();
1187     }
1188     #endif
1189 }
1190
1191 const char *
1192 IsoHandlerManager::eHSToString(enum eHandlerStates s) {
1193     switch (s) {
1194         default: return "Invalid";
1195         case E_Created: return "Created";
1196         case E_Prepared: return "Prepared";
1197         case E_Running: return "Running";
1198         case E_Error: return "Error";
1199     }
1200 }
1201
1202
1203 // ISOHANDLER
1204
1205 /* the C callbacks */
1206 enum raw1394_iso_disposition
1207 IsoHandlerManager::IsoHandler::iso_transmit_handler(raw1394handle_t handle,
1208         unsigned char *data, unsigned int *length,
1209         unsigned char *tag, unsigned char *sy,
1210         int cycle, unsigned int dropped1) {
1211
1212     IsoHandler *xmitHandler = static_cast<IsoHandler *>(raw1394_get_userdata(handle));
1213     assert(xmitHandler);
1214     unsigned int skipped = (dropped1 & 0xFFFF0000) >> 16;
1215     unsigned int dropped = dropped1 & 0xFFFF;
1216     return xmitHandler->getPacket(data, length, tag, sy, cycle, dropped, skipped);
1217 }
1218
1219 enum raw1394_iso_disposition
1220 IsoHandlerManager::IsoHandler::iso_receive_handler(raw1394handle_t handle, unsigned char *data,
1221                         unsigned int length, unsigned char channel,
1222                         unsigned char tag, unsigned char sy, unsigned int cycle,
1223                         unsigned int dropped) {
1224
1225     IsoHandler *recvHandler = static_cast<IsoHandler *>(raw1394_get_userdata(handle));
1226     assert(recvHandler);
1227
1228     return recvHandler->putPacket(data, length, channel, tag, sy, cycle, dropped);
1229 }
1230
1231 IsoHandlerManager::IsoHandler::IsoHandler(IsoHandlerManager& manager, enum EHandlerType t)
1232    : m_manager( manager )
1233    , m_type ( t )
1234    , m_handle( NULL )
1235    , m_buf_packets( 400 )
1236    , m_max_packet_size( 1024 )
1237    , m_irq_interval( -1 )
1238    , m_last_cycle( -1 )
1239    , m_last_now( 0xFFFFFFFF )
1240    , m_last_packet_handled_at( 0xFFFFFFFF )
1241    , m_receive_mode ( RAW1394_DMA_PACKET_PER_BUFFER )
1242    , m_Client( 0 )
1243    , m_speed( RAW1394_ISO_SPEED_400 )
1244    , m_State( eHS_Stopped )
1245    , m_NextState( eHS_Stopped )
1246    , m_switch_on_cycle(0)
1247 #ifdef DEBUG
1248    , m_packets ( 0 )
1249    , m_dropped( 0 )
1250    , m_skipped( 0 )
1251    , m_min_ahead( 7999 )
1252 #endif
1253 {
1254     pthread_mutex_init(&m_disable_lock, NULL);
1255 }
1256
1257 IsoHandlerManager::IsoHandler::IsoHandler(IsoHandlerManager& manager, enum EHandlerType t,
1258                        unsigned int buf_packets, unsigned int max_packet_size, int irq)
1259    : m_manager( manager )
1260    , m_type ( t )
1261    , m_handle( NULL )
1262    , m_buf_packets( buf_packets )
1263    , m_max_packet_size( max_packet_size )
1264    , m_irq_interval( irq )
1265    , m_last_cycle( -1 )
1266    , m_last_now( 0xFFFFFFFF )
1267    , m_last_packet_handled_at( 0xFFFFFFFF )
1268    , m_receive_mode ( RAW1394_DMA_PACKET_PER_BUFFER )
1269    , m_Client( 0 )
1270    , m_speed( RAW1394_ISO_SPEED_400 )
1271    , m_State( eHS_Stopped )
1272    , m_NextState( eHS_Stopped )
1273    , m_switch_on_cycle(0)
1274 #ifdef DEBUG
1275    , m_packets ( 0 )
1276    , m_dropped( 0 )
1277    , m_skipped( 0 )
1278    , m_min_ahead( 7999 )
1279 #endif
1280 {
1281     pthread_mutex_init(&m_disable_lock, NULL);
1282 }
1283
1284 IsoHandlerManager::IsoHandler::IsoHandler(IsoHandlerManager& manager, enum EHandlerType t, unsigned int buf_packets,
1285                        unsigned int max_packet_size, int irq,
1286                        enum raw1394_iso_speed speed)
1287    : m_manager( manager )
1288    , m_type ( t )
1289    , m_handle( NULL )
1290    , m_buf_packets( buf_packets )
1291    , m_max_packet_size( max_packet_size )
1292    , m_irq_interval( irq )
1293    , m_last_cycle( -1 )
1294    , m_last_now( 0xFFFFFFFF )
1295    , m_last_packet_handled_at( 0xFFFFFFFF )
1296    , m_receive_mode ( RAW1394_DMA_PACKET_PER_BUFFER )
1297    , m_Client( 0 )
1298    , m_speed( speed )
1299    , m_State( eHS_Stopped )
1300    , m_NextState( eHS_Stopped )
1301    , m_switch_on_cycle(0)
1302 #ifdef DEBUG
1303    , m_packets( 0 )
1304    , m_dropped( 0 )
1305    , m_skipped( 0 )
1306    , m_min_ahead( 7999 )
1307 #endif
1308 {
1309     pthread_mutex_init(&m_disable_lock, NULL);
1310 }
1311
1312 IsoHandlerManager::IsoHandler::~IsoHandler() {
1313 // Don't call until libraw1394's raw1394_new_handle() function has been
1314 // fixed to correctly initialise the iso_packet_infos field.  Bug is
1315 // confirmed present in libraw1394 1.2.1.  In any case,
1316 // raw1394_destroy_handle() will do any iso system shutdown required.
1317 //     raw1394_iso_shutdown(m_handle);
1318
1319 // Typically, by the time this function is called the IsoTask thread would
1320 // have called disable() on the handler (in the FW_ISORCV/FW_ISOXMT
1321 // threads).  However, the raw1394_destroy_handle() call therein takes
1322 // upwards of 20 milliseconds to complete under the new kernel firewire
1323 // stack, and may not have completed by the time ~IsoHandler() is called by
1324 // the "jackd" thread.  Thus, wait for the lock before testing the state
1325 // of the handle so any in-progress disable() is complete.
1326     if (pthread_mutex_trylock(&m_disable_lock) == EBUSY) {
1327         pthread_mutex_lock(&m_disable_lock);
1328         pthread_mutex_unlock(&m_disable_lock);
1329     }
1330     if(m_handle) {
1331         if (m_State == eHS_Running) {
1332             debugError("BUG: Handler still running!\n");
1333             disable();
1334         }
1335     }
1336     pthread_mutex_destroy(&m_disable_lock);
1337 }
1338
1339 bool
1340 IsoHandlerManager::IsoHandler::canIterateClient()
1341 {
1342     debugOutputExtreme(DEBUG_LEVEL_VERY_VERBOSE, "checking...\n");
1343     if(m_Client) {
1344         bool result;
1345
1346         if (m_type == eHT_Receive) {
1347             result = m_Client->canProducePacket();
1348         } else {
1349             result = m_Client->canConsumePacket();
1350         }
1351         debugOutputExtreme(DEBUG_LEVEL_VERY_VERBOSE, " returns %d\n", result);
1352         return result && (m_State != eHS_Error);
1353     } else {
1354         debugOutputExtreme(DEBUG_LEVEL_VERY_VERBOSE, " no client\n");
1355     }
1356     return false;
1357 }
1358
1359 bool
1360 IsoHandlerManager::IsoHandler::iterate() {
1361     return iterate(m_manager.get1394Service().getCycleTimer());
1362 }
1363
1364 bool
1365 IsoHandlerManager::IsoHandler::iterate(uint32_t cycle_timer_now) {
1366     debugOutputExtreme(DEBUG_LEVEL_VERY_VERBOSE, "(%p, %s) Iterating ISO handler at %08X...\n",
1367                        this, getTypeString(), cycle_timer_now);
1368     m_last_now = cycle_timer_now;
1369     if(m_State == eHS_Running) {
1370         assert(m_handle);
1371
1372         #if ISOHANDLER_FLUSH_BEFORE_ITERATE
1373         // this flushes all packets received since the poll() returned
1374         // from kernel to userspace such that they are processed by this
1375         // iterate. Doing so might result in lower latency capability
1376         // and/or better reliability
1377         if(m_type == eHT_Receive) {
1378             raw1394_iso_recv_flush(m_handle);
1379         }
1380         #endif
1381
1382         if(raw1394_loop_iterate(m_handle)) {
1383             debugError( "IsoHandler (%p): Failed to iterate handler: %s\n",
1384                         this, strerror(errno));
1385             return false;
1386         }
1387         debugOutputExtreme(DEBUG_LEVEL_VERY_VERBOSE, "(%p, %s) done interating ISO handler...\n",
1388                            this, getTypeString());
1389         return true;
1390     } else {
1391         debugOutput(DEBUG_LEVEL_VERBOSE, "(%p, %s) Not iterating a non-running handler...\n",
1392                     this, getTypeString());
1393         return false;
1394     }
1395 }
1396
1397 /**
1398  * Bus reset handler
1399  *
1400  * @return ?
1401  */
1402
1403 bool
1404 IsoHandlerManager::IsoHandler::handleBusReset()
1405 {
1406     debugOutput( DEBUG_LEVEL_NORMAL, "bus reset...\n");
1407     m_last_packet_handled_at = 0xFFFFFFFF;
1408
1409     #define CSR_CYCLE_TIME            0x200
1410     #define CSR_REGISTER_BASE  0xfffff0000000ULL
1411     // do a simple read on ourself in order to update the internal structures
1412     // this avoids read failures after a bus reset
1413     quadlet_t buf=0;
1414     raw1394_read(m_handle, raw1394_get_local_id(m_handle),
1415                  CSR_REGISTER_BASE | CSR_CYCLE_TIME, 4, &buf);
1416
1417     return m_Client->handleBusReset();
1418 }
1419
1420 /**
1421  * Call this if you find out that this handler has died for some
1422  * external reason.
1423  */
1424 void
1425 IsoHandlerManager::IsoHandler::notifyOfDeath()
1426 {
1427     m_State = eHS_Error;
1428     m_NextState = eHS_Error;
1429
1430     // notify the client of the fact that we have died
1431     m_Client->handlerDied();
1432
1433     // wake ourselves up
1434     if(m_handle) raw1394_wake_up(m_handle);
1435 }
1436
1437 void IsoHandlerManager::IsoHandler::dumpInfo()
1438 {
1439     int channel=-1;
1440     if (m_Client) channel=m_Client->getChannel();
1441
1442     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Handler type................: %s\n",
1443             getTypeString());
1444     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Port, Channel...............: %2d, %2d\n",
1445             m_manager.get1394Service().getPort(), channel);
1446     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Buffer, MaxPacketSize, IRQ..: %4d, %4d, %4d\n",
1447             m_buf_packets, m_max_packet_size, m_irq_interval);
1448     if (this->getType() == eHT_Transmit) {
1449         debugOutputShort( DEBUG_LEVEL_NORMAL, "  Speed ..................: %2d\n",
1450                                             m_speed);
1451         #ifdef DEBUG
1452         debugOutputShort( DEBUG_LEVEL_NORMAL, "  Min ISOXMT bufferfill : %04d\n", m_min_ahead);
1453         #endif
1454     }
1455     #ifdef DEBUG
1456     debugOutputShort( DEBUG_LEVEL_NORMAL, "  Last cycle, dropped.........: %4d, %4u, %4u\n",
1457             m_last_cycle, m_dropped, m_skipped);
1458     #endif
1459
1460 }
1461
1462 void IsoHandlerManager::IsoHandler::setVerboseLevel(int l)
1463 {
1464     setDebugLevel(l);
1465     debugOutput( DEBUG_LEVEL_VERBOSE, "Setting verbose level to %d...\n", l );
1466 }
1467
1468 bool IsoHandlerManager::IsoHandler::registerStream(StreamProcessor *stream)
1469 {
1470     assert(stream);
1471     debugOutput( DEBUG_LEVEL_VERBOSE, "registering stream (%p)\n", stream);
1472
1473     if (m_Client) {
1474             debugFatal( "Generic IsoHandlers can have only one client\n");
1475             return false;
1476     }
1477     m_Client=stream;
1478     return true;
1479 }
1480
1481 bool IsoHandlerManager::IsoHandler::unregisterStream(StreamProcessor *stream)
1482 {
1483     assert(stream);
1484     debugOutput( DEBUG_LEVEL_VERBOSE, "unregistering stream (%p)\n", stream);
1485
1486     if(stream != m_Client) {
1487             debugFatal( "no client registered\n");
1488             return false;
1489     }
1490     m_Client=0;
1491     return true;
1492 }
1493
1494 // ISO packet interface
1495 enum raw1394_iso_disposition IsoHandlerManager::IsoHandler::putPacket(
1496                     unsigned char *data, unsigned int length,
1497                     unsigned char channel, unsigned char tag, unsigned char sy,
1498                     unsigned int cycle, unsigned int dropped) {
1499     // keep track of dropped cycles
1500     int dropped_cycles = 0;
1501     if (m_last_cycle != (int)cycle && m_last_cycle != -1 && m_manager.m_MissedCyclesOK == false) {
1502         dropped_cycles = diffCycles(cycle, m_last_cycle) - 1;
1503         #ifdef DEBUG
1504         if (dropped_cycles < 0) {
1505             debugWarning("(%p) dropped < 1 (%d), cycle: %d, last_cycle: %d, dropped: %d\n",
1506                          this, dropped_cycles, cycle, m_last_cycle, dropped);
1507         }
1508         if (dropped_cycles > 0) {
1509             debugOutput(DEBUG_LEVEL_VERBOSE,
1510                         "(%p) dropped %d packets on cycle %u, 'dropped'=%u, cycle=%d, m_last_cycle=%d\n",
1511                         this, dropped_cycles, cycle, dropped, cycle, m_last_cycle);
1512             m_dropped += dropped_cycles;
1513         }
1514         #endif
1515     }
1516     m_last_cycle = cycle;
1517
1518     // the m_last_now value is set when the iterate() function is called.
1519     uint32_t now_cycles = CYCLE_TIMER_GET_CYCLES(m_last_now);
1520
1521     // two cases can occur:
1522     // (1) this packet has been received before iterate() was called (normal case).
1523     // (2) this packet has been received after iterate() was called.
1524     //     happens when the kernel flushes more packets while we are already processing.
1525     //
1526     // In case (1) now_cycles is a small number of cycles larger than cycle. In
1527     // case (2) now_cycles is a small number of cycles smaller than cycle.
1528     // hence  abs(diffCycles(now_cycles, cycles)) has to be 'small'
1529
1530     // we can calculate the time of arrival for this packet as
1531     // 'now' + diffCycles(cycles, now_cycles) * TICKS_PER_CYCLE
1532     // in its properly wrapped version
1533     int64_t diff_cycles = diffCycles(cycle, now_cycles);
1534     int64_t tmp = CYCLE_TIMER_TO_TICKS(m_last_now);
1535     tmp += diff_cycles * (int64_t)TICKS_PER_CYCLE;
1536     uint64_t pkt_ctr_ticks = wrapAtMinMaxTicks(tmp);
1537     uint32_t pkt_ctr = TICKS_TO_CYCLE_TIMER(pkt_ctr_ticks);
1538     #ifdef DEBUG
1539     if( (now_cycles < cycle)
1540         && diffCycles(now_cycles, cycle) < 0
1541         // ignore this on dropped cycles, since it's normal
1542         // that now is ahead on the received packets (as we miss packets)
1543         && dropped_cycles == 0)
1544     {
1545         debugOutput(DEBUG_LEVEL_VERY_VERBOSE, "Special non-unwrapping happened\n");
1546     }
1547     #endif
1548
1549     #if ISOHANDLER_CHECK_CTR_RECONSTRUCTION
1550     // add a seconds field
1551     uint32_t now = m_manager.get1394Service().getCycleTimer();
1552     uint32_t now_secs_ref = CYCLE_TIMER_GET_SECS(now);
1553     // causality results in the fact that 'now' is always after 'cycle'
1554     // or at best, equal (if this handler was called within 125us after
1555     // the packet was on the wire).
1556     if(CYCLE_TIMER_GET_CYCLES(now) < cycle) {
1557         // the cycle field has wrapped, substract one second
1558         if(now_secs_ref == 0) {
1559             now_secs_ref = 127;
1560         } else  {
1561             now_secs_ref -= 1;
1562         }
1563     }
1564     uint32_t pkt_ctr_ref = cycle << 12;
1565     pkt_ctr_ref |= (now_secs_ref & 0x7F) << 25;
1566
1567     if((pkt_ctr & ~0x0FFFL) != pkt_ctr_ref) {
1568         debugWarning("reconstructed CTR counter discrepancy\n");
1569         debugWarning(" ingredients: %X, %X, %X, %X, %X, %d, %ld, %ld, %"PRId64"\n",
1570                      cycle, pkt_ctr_ref, pkt_ctr,
1571                      now, m_last_now, now_secs_ref,
1572                      (long int)CYCLE_TIMER_GET_SECS(now),
1573                      (long int)CYCLE_TIMER_GET_SECS(m_last_now),
1574                      tmp);
1575         debugWarning(" diffcy = %"PRId64" \n", diff_cycles);
1576     }
1577     #endif
1578     m_last_packet_handled_at = pkt_ctr;
1579
1580     // leave the offset field (for now?)
1581
1582     debugOutputExtreme(DEBUG_LEVEL_ULTRA_VERBOSE,
1583                 "received packet: length=%d, channel=%d, cycle=%d, at %08X\n",
1584                 length, channel, cycle, pkt_ctr);
1585     m_packets++;
1586     #ifdef DEBUG
1587     if (length > m_max_packet_size) {
1588         debugWarning("(%p, %s) packet too large: len=%u max=%u\n",
1589                      this, getTypeString(), length, m_max_packet_size);
1590     }
1591     if(m_last_cycle == -1) {
1592         debugOutput(DEBUG_LEVEL_VERBOSE, "Handler for %s SP %p is alive (cycle = %u)\n", getTypeString(), this, cycle);
1593     }
1594     #endif
1595
1596     // iterate the client if required
1597     if(m_Client)
1598         return m_Client->putPacket(data, length, channel, tag, sy, pkt_ctr, dropped_cycles);
1599
1600     return RAW1394_ISO_OK;
1601 }
1602
1603 enum raw1394_iso_disposition
1604 IsoHandlerManager::IsoHandler::getPacket(unsigned char *data, unsigned int *length,
1605                       unsigned char *tag, unsigned char *sy,
1606                       int cycle, unsigned int dropped, unsigned int skipped) {
1607
1608     uint32_t pkt_ctr;
1609     if (cycle < 0) {
1610         // mark invalid
1611         pkt_ctr = 0xFFFFFFFF;
1612     } else {
1613         // the m_last_now value is set when the iterate() function is called.
1614         uint32_t now_cycles = CYCLE_TIMER_GET_CYCLES(m_last_now);
1615
1616         // two cases can occur:
1617         // (1) this packet has been received before iterate() was called (normal case).
1618         // (2) this packet has been received after iterate() was called.
1619         //     happens when the kernel flushes more packets while we are already processing.
1620         //
1621         // In case (1) now_cycles is a small number of cycles larger than cycle. In
1622         // case (2) now_cycles is a small number of cycles smaller than cycle.
1623         // hence  abs(diffCycles(now_cycles, cycles)) has to be 'small'
1624
1625         // we can calculate the time of arrival for this packet as
1626         // 'now' + diffCycles(cycles, now_cycles) * TICKS_PER_CYCLE
1627         // in its properly wrapped version
1628         int64_t diff_cycles = diffCycles(cycle, now_cycles);
1629         int64_t tmp = CYCLE_TIMER_TO_TICKS(m_last_now);
1630         tmp += diff_cycles * (int64_t)TICKS_PER_CYCLE;
1631         uint64_t pkt_ctr_ticks = wrapAtMinMaxTicks(tmp);
1632         pkt_ctr = TICKS_TO_CYCLE_TIMER(pkt_ctr_ticks);
1633
1634         #if ISOHANDLER_CHECK_CTR_RECONSTRUCTION
1635         // add a seconds field
1636         uint32_t now = m_manager.get1394Service().getCycleTimer();
1637         uint32_t now_secs_ref = CYCLE_TIMER_GET_SECS(now);
1638         // causality results in the fact that 'now' is always after 'cycle'
1639         if(CYCLE_TIMER_GET_CYCLES(now) > (unsigned int)cycle) {
1640             // the cycle field has wrapped, add one second
1641             now_secs_ref += 1;
1642             // no need for this:
1643             if(now_secs_ref == 128) {
1644                now_secs_ref = 0;
1645             }
1646         }
1647         uint32_t pkt_ctr_ref = cycle << 12;
1648         pkt_ctr_ref |= (now_secs_ref & 0x7F) << 25;
1649
1650         if(((pkt_ctr & ~0x0FFFL) != pkt_ctr_ref) && (m_packets > m_buf_packets)) {
1651             debugWarning("reconstructed CTR counter discrepancy\n");
1652             debugWarning(" ingredients: %X, %X, %X, %X, %X, %d, %ld, %ld, %"PRId64"\n",
1653                         cycle, pkt_ctr_ref, pkt_ctr,
1654                          now, m_last_now, now_secs_ref,
1655                          (long int)CYCLE_TIMER_GET_SECS(now),
1656                          (long int)CYCLE_TIMER_GET_SECS(m_last_now),
1657                          tmp);
1658             debugWarning(" diffcy = %"PRId64" \n", diff_cycles);
1659         }
1660         #endif
1661     }
1662     if (m_packets < m_buf_packets) { // these are still prebuffer packets
1663         m_last_packet_handled_at = 0xFFFFFFFF;
1664     } else {
1665         m_last_packet_handled_at = pkt_ctr;
1666     }
1667     debugOutputExtreme(DEBUG_LEVEL_ULTRA_VERBOSE,
1668                 "sending packet: length=%d, cycle=%d, at %08X\n",
1669                 *length, cycle, pkt_ctr);
1670
1671     m_packets++;
1672
1673     #ifdef DEBUG
1674     if(m_last_cycle == -1) {
1675         debugOutput(DEBUG_LEVEL_VERBOSE, "Handler for %s SP %p is alive. cycle=%d state=%i\n", getTypeString(), this, cycle, m_State);
1676     }
1677     #endif
1678
1679     // keep track of dropped cycles
1680     int dropped_cycles = 0;
1681     if (m_last_cycle != cycle && m_last_cycle != -1) {
1682         dropped_cycles = diffCycles(cycle, m_last_cycle) - 1;
1683         // correct for skipped packets
1684         // since those are not dropped, but only delayed
1685         dropped_cycles -= skipped;
1686
1687         #ifdef DEBUG
1688         if(skipped) {
1689             debugOutput(DEBUG_LEVEL_VERY_VERBOSE,
1690                         "(%p) skipped %d cycles, cycle: %d, last_cycle: %d, dropped: %d\n",
1691                         this, skipped, cycle, m_last_cycle, dropped);
1692             m_skipped += skipped;
1693         }
1694         if (dropped_cycles < 0) {
1695             debugWarning("(%p) dropped < 1 (%d), cycle: %d, last_cycle: %d, dropped: %d, skipped: %d\n",
1696                          this, dropped_cycles, cycle, m_last_cycle, dropped, skipped);
1697         }
1698         if (dropped_cycles > 0) {
1699             debugOutput(DEBUG_LEVEL_VERBOSE,
1700                         "(%p) dropped %d packets on cycle %u (last_cycle=%u, dropped=%d, skipped: %d)\n",
1701                         this, dropped_cycles, cycle, m_last_cycle, dropped, skipped);
1702             m_dropped += dropped_cycles - skipped;
1703         }
1704         #endif
1705     }
1706     if (cycle >= 0) {
1707         m_last_cycle = cycle;
1708        
1709         #ifdef DEBUG
1710 /*        int ahead = diffCycles(cycle, now_cycles);
1711         if (ahead < m_min_ahead) m_min_ahead = ahead;
1712 */
1713         #endif
1714     }
1715
1716     #ifdef DEBUG
1717     if (dropped > 0) {
1718         debugOutput(DEBUG_LEVEL_VERBOSE,
1719                     "(%p) OHCI issue on cycle %u (dropped_cycles=%d, last_cycle=%u, dropped=%d, skipped: %d)\n",
1720                     this, cycle, dropped_cycles, m_last_cycle, dropped, skipped);
1721     }
1722     #endif
1723
1724     if(m_Client) {
1725         enum raw1394_iso_disposition retval;
1726         retval = m_Client->getPacket(data, length, tag, sy, pkt_ctr, dropped_cycles, skipped, m_max_packet_size);
1727         #ifdef DEBUG
1728         if (*length > m_max_packet_size) {
1729             debugWarning("(%p, %s) packet too large: len=%u max=%u\n",
1730                          this, getTypeString(), *length, m_max_packet_size);
1731         }
1732         #endif
1733             return retval;
1734     }
1735
1736     *tag = 0;
1737     *sy = 0;
1738     *length = 0;
1739     return RAW1394_ISO_OK;
1740 }
1741
1742 bool
1743 IsoHandlerManager::IsoHandler::enable(int cycle)
1744 {
1745     debugOutput( DEBUG_LEVEL_VERBOSE, "start on cycle %d\n", cycle);
1746
1747     // check the state
1748     if(m_State != eHS_Stopped) {
1749         debugError("Incorrect state, expected eHS_Stopped, got %d\n",(int)m_State);
1750         return false;
1751     }
1752
1753     assert(m_handle == NULL);
1754
1755     // create a handle for the ISO traffic
1756     m_handle = raw1394_new_handle_on_port( m_manager.get1394Service().getPort() );
1757     if ( !m_handle ) {
1758         if ( !errno ) {
1759             debugError("libraw1394 not compatible\n");
1760         } else {
1761             debugError("Could not get 1394 handle: %s\n", strerror(errno) );
1762             debugError("Are ieee1394 and raw1394 drivers loaded?\n");
1763         }
1764         return false;
1765     }
1766     raw1394_set_userdata(m_handle, static_cast<void *>(this));
1767
1768     // Reset housekeeping data before preparing and starting the handler.
1769     // If only done afterwards, the transmit handler could be called before
1770     // these have been reset, leading to problems in getPacket().
1771 #ifdef DEBUG
1772     m_min_ahead = 7999;
1773 #endif
1774     m_packets = 0;
1775     m_last_cycle = -1;
1776
1777     // indicate that the first iterate() still has to occur.
1778     m_last_now = 0xFFFFFFFF;
1779     m_last_packet_handled_at = 0xFFFFFFFF;
1780
1781     // prepare the handler, allocate the resources
1782     debugOutput( DEBUG_LEVEL_VERBOSE, "Preparing iso handler (%p, client=%p)\n", this, m_Client);
1783     dumpInfo();
1784     if (getType() == eHT_Receive) {
1785         if(raw1394_iso_recv_init(m_handle,
1786                                 iso_receive_handler,
1787                                 m_buf_packets,
1788                                 m_max_packet_size,
1789                                 m_Client->getChannel(),
1790                                 m_receive_mode,
1791                                 m_irq_interval)) {
1792             debugFatal("Could not do receive initialization (PACKET_PER_BUFFER)!\n" );
1793             debugFatal("  %s\n",strerror(errno));
1794             return false;
1795         }
1796
1797         if(raw1394_iso_recv_start(m_handle, cycle, -1, 0)) {
1798             debugFatal("Could not start receive handler (%s)\n",strerror(errno));
1799             dumpInfo();
1800             return false;
1801         }
1802     } else {
1803         if(raw1394_iso_xmit_init(m_handle,
1804                                 iso_transmit_handler,
1805                                 m_buf_packets,
1806                                 m_max_packet_size,
1807                                 m_Client->getChannel(),
1808                                 m_speed,
1809                                 m_irq_interval)) {
1810             debugFatal("Could not do xmit initialisation!\n" );
1811             return false;
1812         }
1813
1814         if(raw1394_iso_xmit_start(m_handle, cycle, 0)) {
1815             debugFatal("Could not start xmit handler (%s)\n", strerror(errno));
1816             dumpInfo();
1817             return false;
1818         }
1819     }
1820
1821     m_State = eHS_Running;
1822     m_NextState = eHS_Running;
1823     return true;
1824 }
1825
1826 bool
1827 IsoHandlerManager::IsoHandler::disable()
1828 {
1829     signed int i, have_lock = 0;
1830
1831     debugOutput( DEBUG_LEVEL_VERBOSE, "(%p, %s) enter...\n",
1832                  this, (m_type==eHT_Receive?"Receive":"Transmit"));
1833
1834     i = pthread_mutex_trylock(&m_disable_lock);
1835     if (i == 0)
1836         have_lock = 1;
1837     else
1838     if (i == EBUSY) {
1839         // Some other thread is disabling this handler, a process which can
1840         // take considerable time when using the new kernel firewire stack.
1841         // Wait until it is finished before returning so the present caller
1842         // can act knowing that the disable has occurred and is complete
1843         // (which is what normally would be expected).
1844         debugOutput( DEBUG_LEVEL_VERBOSE, "waiting for disable lock\n");
1845         pthread_mutex_lock(&m_disable_lock);
1846         debugOutput( DEBUG_LEVEL_VERBOSE, "now have disable lock\n");
1847         if (m_State == eHS_Stopped) {
1848             debugOutput( DEBUG_LEVEL_VERBOSE, "another disable() has completed\n");
1849             pthread_mutex_unlock(&m_disable_lock);
1850             return true;
1851         }
1852         have_lock = 1;
1853     }
1854
1855     // check state
1856     if(m_State != eHS_Running) {
1857         debugError("Incorrect state, expected eHS_Running, got %d\n",(int)m_State);
1858         if (have_lock)
1859             pthread_mutex_unlock(&m_disable_lock);
1860         return false;
1861     }
1862
1863     assert(m_handle != NULL);
1864
1865     debugOutput( DEBUG_LEVEL_VERBOSE, "(%p, %s) wake up handle...\n",
1866                  this, (m_type==eHT_Receive?"Receive":"Transmit"));
1867
1868     // wake up any waiting reads/polls
1869     raw1394_wake_up(m_handle);
1870
1871     // this is put here to try and avoid the
1872     // Runaway context problem
1873     // don't know if it will help though.
1874 /*    if(m_State != eHS_Error) { // if the handler is dead, this might block forever
1875         raw1394_iso_xmit_sync(m_handle);
1876     }*/
1877     debugOutput( DEBUG_LEVEL_VERBOSE, "(%p, %s) stop...\n",
1878                  this, (m_type==eHT_Receive?"Receive":"Transmit"));
1879
1880     // stop iso traffic
1881     raw1394_iso_stop(m_handle);
1882     // deallocate resources
1883
1884     // Don't call until libraw1394's raw1394_new_handle() function has been
1885     // fixed to correctly initialise the iso_packet_infos field.  Bug is
1886     // confirmed present in libraw1394 1.2.1.
1887     raw1394_iso_shutdown(m_handle);
1888
1889     // When running on the new kernel firewire stack, this call can take of
1890     // the order of 20 milliseconds to return, in which time other threads
1891     // may wish to test the state of the handler and call this function
1892     // themselves.  The m_disable_lock mutex is used to work around this.
1893     raw1394_destroy_handle(m_handle);
1894     m_handle = NULL;
1895
1896     m_State = eHS_Stopped;
1897     m_NextState = eHS_Stopped;
1898
1899     if (have_lock)
1900         pthread_mutex_unlock(&m_disable_lock);
1901     return true;
1902 }
1903
1904 // functions to request enable or disable at the next opportunity
1905 bool
1906 IsoHandlerManager::IsoHandler::requestEnable(int cycle)
1907 {
1908     if (m_State == eHS_Running) {
1909         debugError("Enable requested on enabled stream '%s'\n", getTypeString());
1910         return false;
1911     }
1912     if (m_State != eHS_Stopped) {
1913         debugError("Enable requested on stream '%s' with state: %d\n", getTypeString(), m_State);
1914         return false;
1915     }
1916     m_NextState = eHS_Running;
1917     return true;
1918 }
1919
1920 bool
1921 IsoHandlerManager::IsoHandler::requestDisable()
1922 {
1923     if (m_State == eHS_Stopped) {
1924         // Don't treat this as an error condition because during a user
1925         // shutdown the stream would have been disabled by
1926         // stopHandlerForStream().  Therefore when requestDisable() is
1927         // subnsequently called by IsoHandlerManager::stopHandlers() in the
1928         // IsoHandlerManager destructor with the stream disabled the
1929         // condition is not an error.
1930         //
1931         // For now print a warning, but this might be removed in future if
1932         // the above framework remains in place.
1933         debugWarning("Disable requested on disabled stream\n");
1934         return true;
1935     }
1936     if (m_State != eHS_Running) {
1937         debugError("Disable requested on stream with state=%d\n", m_State);
1938         return false;
1939     }
1940     m_NextState = eHS_Stopped;
1941     return true;
1942 }
1943
1944 // Explicitly preset m_switch_on_cycle since requestEnable doesn't do this
1945 // and thus all enables requested via that route always occur on cycle 0.
1946 void
1947 IsoHandlerManager::IsoHandler::setIsoStartCycle(signed int cycle)
1948 {
1949   m_switch_on_cycle = cycle;
1950 }
1951
1952 void
1953 IsoHandlerManager::IsoHandler::updateState()
1954 {
1955     // execute state changes requested
1956     if(m_State != m_NextState) {
1957         debugOutput(DEBUG_LEVEL_VERBOSE, "(%p) handler needs state update from %d => %d\n", this, m_State, m_NextState);
1958         if(m_State == eHS_Stopped && m_NextState == eHS_Running) {
1959             debugOutput(DEBUG_LEVEL_VERBOSE, "handler has to be enabled\n");
1960             enable(m_switch_on_cycle);
1961         } else if(m_State == eHS_Running && m_NextState == eHS_Stopped) {
1962             debugOutput(DEBUG_LEVEL_VERBOSE, "handler has to be disabled\n");
1963             disable();
1964         } else {
1965             debugError("Unknown state transition\n");
1966         }
1967     }
1968 }
1969
1970 /**
1971  * @brief convert a EHandlerType to a string
1972  * @param t the type
1973  * @return a char * describing the state
1974  */
1975 const char *
1976 IsoHandlerManager::IsoHandler::eHTToString(enum EHandlerType t) {
1977     switch (t) {
1978         case eHT_Receive: return "Receive";
1979         case eHT_Transmit: return "Transmit";
1980         default: return "error: unknown type";
1981     }
1982 }
Note: See TracBrowser for help on using the browser.