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

Revision 2177, 70.9 kB (checked in by jwoithe, 8 years ago)

More work on ticket #242. sem_timedwait() can only work against CLOCK_REALTIME, so the time used to construct its absolute timeout value must be acquired from CLOCK_REALTIME regardless of the clock used by Util::SystemTimeSource?.

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