root/branches/ppalmers-streaming/src/debugmodule/debugmodule.cpp

Revision 720, 17.2 kB (checked in by ppalmers, 13 years ago)

first working version of the reworked streaming code

  • Property svn:eol-style set to native
  • Property svn:keywords set to Author Date Id Revision
Line 
1 /*
2  * Copyright (C) 2005-2007 by Daniel Wagner
3  * Copyright (C) 2005-2007 by Pieter Palmers
4  *
5  * This file is part of FFADO
6  * FFADO = Free Firewire (pro-)audio drivers for linux
7  *
8  * FFADO is based upon FreeBoB
9  *
10  * This library is free software; you can redistribute it and/or
11  * modify it under the terms of the GNU Lesser General Public
12  * License version 2.1, as published by the Free Software Foundation;
13  *
14  * This library 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 GNU
17  * Lesser General Public License for more details.
18  *
19  * You should have received a copy of the GNU Lesser General Public
20  * License along with this library; if not, write to the Free Software
21  * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston,
22  * MA 02110-1301 USA
23  */
24
25 #include "debugmodule.h"
26
27 #include <stdarg.h>
28 #include <netinet/in.h>
29
30 #include <iostream>
31
32 #include <time.h>
33
34 #define DO_MESSAGE_BUFFER_PRINT
35
36 #ifndef DO_MESSAGE_BUFFER_PRINT
37     #warning Printing debug info without ringbuffer, not RT-safe!
38 #endif
39
40 using namespace std;
41
42 struct ColorEntry  {
43     const char* preSequence;
44     const char* postSequence;
45 };
46
47 ColorEntry colorTable[] = {
48     { "\033[31mFatal",   "\033[0m" },
49     { "\033[31mError",   "\033[0m" },
50     { "\033[31mWarning", "\033[0m" },
51     { "Debug",           ""        },
52 };
53
54
55 DebugModule::DebugModule( std::string name,  debug_level_t level )
56     : m_name( name )
57     , m_level( level )
58 {
59     if ( !DebugModuleManager::instance()->registerModule( *this ) ) {
60         cerr << "Could not register DebugModule (" << name
61              << ") at DebugModuleManager"
62              << endl;
63     }
64 }
65
66 DebugModule::~DebugModule()
67 {
68 //     if ( m_level >= eDL_VeryVerbose ) {
69 //         cout << "Unregistering "
70 //              << this->getName()
71 //              << " at DebugModuleManager"
72 //              << endl;
73 //     }
74     if ( !DebugModuleManager::instance()->unregisterModule( *this ) ) {
75         cerr << "Could not unregister DebugModule at DebugModuleManager"
76              << endl;
77     }
78
79 }
80
81 void
82 DebugModule::printShort( debug_level_t level,
83                          const char* format,
84                          ... ) const
85 {
86
87     // bypass for performance
88 #ifdef IMPLEMENT_BACKLOG
89     if (level > BACKLOG_MIN_LEVEL
90         && level > m_level) {
91         return;
92     }
93 #else
94     if ( level >m_level ) {
95         return;
96     }
97 #endif
98
99     const char *warning = "WARNING: message truncated!\n";
100     const int warning_size = 32;
101     va_list arg;
102     char msg[MB_BUFFERSIZE];
103
104     // format the message such that it remains together
105     int chars_written=0;
106     int retval=0;
107
108     va_start( arg, format );
109     retval = vsnprintf(msg+chars_written, MB_BUFFERSIZE, format, arg);
110     va_end( arg );
111     if (retval >= 0) {  // ignore errors
112         chars_written += retval;
113     }
114
115     // output a warning if the message was truncated
116     if (chars_written == MB_BUFFERSIZE) {
117         snprintf(msg+MB_BUFFERSIZE-warning_size, warning_size, "%s", warning);
118     }
119
120 #ifdef IMPLEMENT_BACKLOG
121     // print to backlog if necessary
122     if (level <= BACKLOG_MIN_LEVEL) {
123         DebugModuleManager::instance()->backlog_print( msg );
124     }
125 #endif
126
127     // print to stderr if necessary
128     if ( level <= m_level ) {
129         DebugModuleManager::instance()->print( msg );
130     }
131 }
132
133 void
134 DebugModule::print( debug_level_t level,
135                     const char*   file,
136                     const char*   function,
137                     unsigned int  line,
138                     const char*   format,
139                     ... ) const
140 {
141     // bypass for performance
142 #ifdef IMPLEMENT_BACKLOG
143     if (level > BACKLOG_MIN_LEVEL
144         && level > m_level) {
145         return;
146     }
147 #else
148     if ( level >m_level ) {
149         return;
150     }
151 #endif
152
153     const char *warning = "WARNING: message truncated!\n";
154     const int warning_size = 32;
155
156     va_list arg;
157     char msg[MB_BUFFERSIZE];
158
159     // remove the path info from the filename
160     const char *f = file;
161     const char *fname = file;
162     while((f=strstr(f, "/"))) {
163         f++; // move away from delimiter
164         fname=f;
165     }
166
167     // add a timing timestamp
168     struct timespec ts;
169     clock_gettime(CLOCK_MONOTONIC, &ts);
170     long unsigned int ts_usec=(uint32_t)(ts.tv_sec * 1000000LL + ts.tv_nsec / 1000LL);
171
172     // format the message such that it remains together
173     int chars_written=0;
174     int retval=0;
175     retval = snprintf(msg, MB_BUFFERSIZE, "%010lu: %s (%s)[%4d] %s: ",
176                       ts_usec, getPreSequence( level ),
177                       fname,  line,  function );
178     if (retval >= 0) chars_written += retval; // ignore errors
179
180     va_start( arg, format );
181     retval = vsnprintf( msg + chars_written,
182                         MB_BUFFERSIZE - chars_written,
183                         format, arg);
184     va_end( arg );
185     if (retval >= 0) chars_written += retval; // ignore errors
186
187     retval = snprintf( msg + chars_written,
188                        MB_BUFFERSIZE - chars_written,
189                        "%s", getPostSequence( level ) );
190     if (retval >= 0) chars_written += retval; // ignore errors
191
192     // output a warning if the message was truncated
193     if (chars_written == MB_BUFFERSIZE) {
194         snprintf(msg + MB_BUFFERSIZE - warning_size,
195                  warning_size,
196                  "%s", warning);
197     }
198
199 #ifdef IMPLEMENT_BACKLOG
200     // print to backlog if necessary
201     if (level <= BACKLOG_MIN_LEVEL) {
202         DebugModuleManager::instance()->backlog_print( msg );
203     }
204 #endif
205
206     // print to stderr if necessary
207     if ( level <= m_level ) {
208         DebugModuleManager::instance()->print( msg );
209     }
210 }
211
212 const char*
213 DebugModule::getPreSequence( debug_level_t level ) const
214 {
215     if ( ( level <= eDL_Normal ) && ( level >= eDL_Fatal ) ) {
216         return colorTable[level].preSequence;
217     }
218     return colorTable[eDL_Normal].preSequence;
219 }
220
221 const char*
222 DebugModule::getPostSequence( debug_level_t level ) const
223 {
224     if ( ( level <= eDL_Normal ) && ( level >= eDL_Fatal ) ) {
225         return colorTable[level].postSequence;
226     }
227     return colorTable[eDL_Normal].postSequence;
228 }
229
230 //--------------------------------------
231
232 DebugModuleManager* DebugModuleManager::m_instance = 0;
233
234 DebugModuleManager::DebugModuleManager()
235     : mb_initialized(0)
236     , mb_inbuffer(0)
237     , mb_outbuffer(0)
238     , mb_overruns(0)
239 #ifdef IMPLEMENT_BACKLOG
240     , bl_mb_inbuffer(0)
241 #endif
242 {
243
244 }
245
246 DebugModuleManager::~DebugModuleManager()
247 {
248     // cleanin up leftover modules
249     for ( DebugModuleVectorIterator it = m_debugModules.begin();
250           it != m_debugModules.end();
251           ++it )
252     {
253         fprintf(stderr,"Cleaning up leftover debug module: %s\n",(*it)->getName().c_str());
254         m_debugModules.erase( it );
255         delete *it;
256     }
257
258     if (!mb_initialized)
259         return;
260
261     pthread_mutex_lock(&mb_write_lock);
262     mb_initialized = 0;
263     pthread_cond_signal(&mb_ready_cond);
264     pthread_mutex_unlock(&mb_write_lock);
265
266     pthread_join(mb_writer_thread, NULL);
267     mb_flush();
268
269     if (mb_overruns)
270         fprintf(stderr, "WARNING: %d message buffer overruns!\n",
271             mb_overruns);
272     else
273         fprintf(stderr, "no message buffer overruns\n");
274
275     pthread_mutex_destroy(&mb_write_lock);
276     pthread_cond_destroy(&mb_ready_cond);
277
278 #ifdef IMPLEMENT_BACKLOG
279     pthread_mutex_destroy(&bl_mb_write_lock);
280 #endif
281
282 }
283
284 bool
285 DebugModuleManager::init()
286 {
287     if (mb_initialized)
288         return true;
289
290         // if ( m_level >= eDL_VeryVerbose )
291         //         cout << "DebugModuleManager init..." << endl;
292
293     pthread_mutex_init(&mb_write_lock, NULL);
294     pthread_mutex_init(&mb_flush_lock, NULL);
295     pthread_cond_init(&mb_ready_cond, NULL);
296
297     mb_overruns = 0;
298     mb_initialized = 1;
299
300 #ifdef IMPLEMENT_BACKLOG
301     pthread_mutex_init(&bl_mb_write_lock, NULL);
302 #endif
303
304     if (pthread_create(&mb_writer_thread, NULL, &mb_thread_func, (void *)this) != 0)
305          mb_initialized = 0;
306
307     return true;
308 }
309
310 DebugModuleManager*
311 DebugModuleManager::instance()
312 {
313     if ( !m_instance ) {
314         m_instance = new DebugModuleManager;
315         if ( !m_instance ) {
316             cerr << "DebugModuleManager::instance Failed to create "
317                  << "DebugModuleManager" << endl;
318         }
319         if ( !m_instance->init() ) {
320             cerr << "DebugModuleManager::instance Failed to init "
321                  << "DebugModuleManager" << endl;
322         }
323     }
324     return m_instance;
325 }
326
327 bool
328 DebugModuleManager::registerModule( DebugModule& debugModule )
329 {
330     bool already_present=false;
331
332     for ( DebugModuleVectorIterator it = m_debugModules.begin();
333           it != m_debugModules.end();
334           ++it )
335     {
336         if ( *it == &debugModule ) {
337             already_present=true;
338             return true;
339         }
340     }
341
342     if (already_present) {
343         cerr << "DebugModuleManager::registerModule: Module already registered: "
344             << "DebugModule (" << debugModule.getName() << ")" << endl;
345     } else {
346         m_debugModules.push_back( &debugModule );
347     }
348     return true;
349 }
350
351 bool
352 DebugModuleManager::unregisterModule( DebugModule& debugModule )
353 {
354
355     for ( DebugModuleVectorIterator it = m_debugModules.begin();
356           it != m_debugModules.end();
357           ++it )
358     {
359         if ( *it == &debugModule ) {
360             m_debugModules.erase( it );
361             return true;
362         }
363     }
364
365     cerr << "DebugModuleManager::unregisterModule: Could not unregister "
366          << "DebugModule (" << debugModule.getName() << ")" << endl;
367     return false;
368 }
369
370 bool
371 DebugModuleManager::setMgrDebugLevel( std::string name, debug_level_t level )
372 {
373     for ( DebugModuleVectorIterator it = m_debugModules.begin();
374           it != m_debugModules.end();
375           ++it )
376     {
377         if ( (*it)->getName() == name ) {
378             return (*it)->setLevel( level );
379         }
380     }
381
382     cerr << "setDebugLevel: Did not find DebugModule ("
383          << name << ")" << endl;
384     return false;
385 }
386
387 void
388 DebugModuleManager::flush()
389 {
390 #ifdef DO_MESSAGE_BUFFER_PRINT
391     mb_flush();
392 #else
393     fflush(stderr);
394 #endif
395 }
396
397 void
398 DebugModuleManager::mb_flush()
399 {
400     /* called WITHOUT the mb_write_lock */
401    
402     /* the flush lock is to allow a flush from multiple threads
403      * this allows a code section that outputs a lot of debug messages
404      * and that can be blocked to flush the buffer itself such that it
405      * does not overflow.
406      */
407     DebugModuleManager *m=DebugModuleManager::instance();
408     pthread_mutex_lock(&m->mb_flush_lock);
409     while (mb_outbuffer != mb_inbuffer) {
410         fputs(mb_buffers[mb_outbuffer], stderr);
411         mb_outbuffer = MB_NEXT(mb_outbuffer);
412     }
413     pthread_mutex_unlock(&m->mb_flush_lock);
414 }
415
416 #ifdef IMPLEMENT_BACKLOG
417 void
418 DebugModuleManager::showBackLog()
419 {
420      DebugModuleManager *m=DebugModuleManager::instance();
421     // locking the flush lock ensures that the backlog is
422     // printed as one entity
423     pthread_mutex_lock(&m->mb_flush_lock);
424     fprintf(stderr, "=====================================================\n");
425     fprintf(stderr, "* BEGIN OF BACKLOG PRINT\n");
426     fprintf(stderr, "=====================================================\n");
427
428     for (unsigned int i=0; i<BACKLOG_MB_BUFFERS;i++) {
429         unsigned int idx=(i+bl_mb_inbuffer)%BACKLOG_MB_BUFFERS;
430         fputs("BL: ", stderr);
431         fputs(bl_mb_buffers[idx], stderr);
432     }
433     fprintf(stderr, "BL: \n");
434
435     fprintf(stderr, "=====================================================\n");
436     fprintf(stderr, "* END OF BACKLOG PRINT\n");
437     fprintf(stderr, "=====================================================\n");
438     pthread_mutex_unlock(&m->mb_flush_lock);
439 }
440
441 void
442 DebugModuleManager::showBackLog(int nblines)
443 {
444      DebugModuleManager *m=DebugModuleManager::instance();
445     // locking the flush lock ensures that the backlog is
446     // printed as one entity
447     pthread_mutex_lock(&m->mb_flush_lock);
448     fprintf(stderr, "=====================================================\n");
449     fprintf(stderr, "* BEGIN OF BACKLOG PRINT\n");
450     fprintf(stderr, "=====================================================\n");
451
452     int lines_to_skip = BACKLOG_MB_BUFFERS - nblines;
453     if (lines_to_skip < 0) lines_to_skip = 0;
454     for (unsigned int i=0; i<BACKLOG_MB_BUFFERS;i++) {
455         if (lines_to_skip-- < 0) {
456             unsigned int idx=(i+bl_mb_inbuffer)%BACKLOG_MB_BUFFERS;
457             fputs("BL: ", stderr);
458             fputs(bl_mb_buffers[idx], stderr);
459         }
460     }
461     fprintf(stderr, "BL: \n");
462
463     fprintf(stderr, "=====================================================\n");
464     fprintf(stderr, "* END OF BACKLOG PRINT\n");
465     fprintf(stderr, "=====================================================\n");
466     pthread_mutex_unlock(&m->mb_flush_lock);
467 }
468 #endif
469
470 void *
471 DebugModuleManager::mb_thread_func(void *arg)
472 {
473
474     DebugModuleManager *m=static_cast<DebugModuleManager *>(arg);
475
476     /* The mutex is only to eliminate collisions between multiple
477      * writer threads and protect the condition variable. */
478      pthread_mutex_lock(&m->mb_write_lock);
479
480     while (m->mb_initialized) {
481          pthread_cond_wait(&m->mb_ready_cond, &m->mb_write_lock);
482
483          /* releasing the mutex reduces contention */
484          pthread_mutex_unlock(&m->mb_write_lock);
485          m->mb_flush();
486          pthread_mutex_lock(&m->mb_write_lock);
487     }
488
489      pthread_mutex_unlock(&m->mb_write_lock);
490
491     return NULL;
492 }
493
494 #ifdef IMPLEMENT_BACKLOG
495 void
496 DebugModuleManager::backlog_print(const char *msg)
497 {
498     unsigned int ntries;
499     struct timespec wait = {0,50000};
500     // the backlog
501     ntries=1;
502     while (ntries) { // try a few times
503         if (pthread_mutex_trylock(&bl_mb_write_lock) == 0) {
504             strncpy(bl_mb_buffers[bl_mb_inbuffer], msg, MB_BUFFERSIZE);
505             bl_mb_inbuffer = BACKLOG_MB_NEXT(bl_mb_inbuffer);
506             pthread_mutex_unlock(&bl_mb_write_lock);
507             break;
508         } else {
509             nanosleep(&wait, NULL);
510             ntries--;
511         }
512     }
513     // just bail out should it have failed
514 }
515 #endif
516
517 void
518 DebugModuleManager::print(const char *msg)
519 {
520 #ifdef DO_MESSAGE_BUFFER_PRINT
521     unsigned int ntries;
522     struct timespec wait = {0,50000};
523 #endif
524
525     if (!mb_initialized) {
526         /* Unable to print message with realtime safety.
527          * Complain and print it anyway. */
528         fprintf(stderr, "ERROR: messagebuffer not initialized: %s",
529             msg);
530         return;
531     }
532
533 #ifdef DO_MESSAGE_BUFFER_PRINT
534     ntries=1;
535     while (ntries) { // try a few times
536         if (pthread_mutex_trylock(&mb_write_lock) == 0) {
537             strncpy(mb_buffers[mb_inbuffer], msg, MB_BUFFERSIZE);
538             mb_inbuffer = MB_NEXT(mb_inbuffer);
539             pthread_cond_signal(&mb_ready_cond);
540             pthread_mutex_unlock(&mb_write_lock);
541             break;
542         } else {
543             nanosleep(&wait, NULL);
544             ntries--;
545         }
546     }
547     if (ntries==0) {  /* lock collision */
548         //         atomic_add(&mb_overruns, 1);
549         // FIXME: atomicity
550         mb_overruns++; // skip the atomicness for now
551     }
552 #else
553     fprintf(stderr,msg);
554 #endif
555 }
556
557 //----------------------------------------
558
559 unsigned char
560 toAscii( unsigned char c )
561 {
562     if ( ( c > 31 ) && ( c < 126) ) {
563         return c;
564     } else {
565         return '.';
566     }
567 }
568
569 /* converts a quadlet to a uchar * buffer
570  * not implemented optimally, but clear
571  */
572 void
573 quadlet2char( quadlet_t quadlet, unsigned char* buff )
574 {
575     *(buff)   = (quadlet>>24)&0xFF;
576     *(buff+1) = (quadlet>>16)&0xFF;
577     *(buff+2) = (quadlet>> 8)&0xFF;
578     *(buff+3) = (quadlet)    &0xFF;
579 }
580
581 void
582 hexDump( unsigned char *data_start, unsigned int length )
583 {
584     unsigned int i=0;
585     unsigned int byte_pos;
586     unsigned int bytes_left;
587
588     if ( length <= 0 ) {
589         return;
590     }
591     if ( length >= 7 ) {
592         for ( i = 0; i < (length-7); i += 8 ) {
593             printf( "%04X: %02X %02X %02X %02X %02X %02X %02X %02X "
594                     "- [%c%c%c%c%c%c%c%c]\n",
595
596                     i,
597
598                     *(data_start+i+0),
599                     *(data_start+i+1),
600                     *(data_start+i+2),
601                     *(data_start+i+3),
602                     *(data_start+i+4),
603                     *(data_start+i+5),
604                     *(data_start+i+6),
605                     *(data_start+i+7),
606
607                     toAscii( *(data_start+i+0) ),
608                     toAscii( *(data_start+i+1) ),
609                     toAscii( *(data_start+i+2) ),
610                     toAscii( *(data_start+i+3) ),
611                     toAscii( *(data_start+i+4) ),
612                     toAscii( *(data_start+i+5) ),
613                     toAscii( *(data_start+i+6) ),
614                     toAscii( *(data_start+i+7) )
615                 );
616         }
617     }
618     byte_pos = i;
619     bytes_left = length - byte_pos;
620
621     printf( "%04X:" ,i );
622     for ( i = byte_pos; i < length; i += 1 ) {
623         printf( " %02X", *(data_start+i) );
624     }
625     for ( i=0; i < 8-bytes_left; i+=1 ) {
626         printf( "   " );
627     }
628
629     printf( " - [" );
630     for ( i = byte_pos; i < length; i += 1) {
631         printf( "%c", toAscii(*(data_start+i)));
632     }
633     for ( i = 0; i < 8-bytes_left; i += 1) {
634         printf( " " );
635     }
636
637     printf( "]" );
638     printf( "\n" );
639 }
640
641 void
642 hexDumpQuadlets( quadlet_t *data, unsigned int length )
643 {
644     unsigned int i=0;
645
646     if ( length <= 0 ) {
647         return;
648     }
649     for (i = 0; i< length; i += 1) {
650         printf( "%02d %04X: %08X (%08X)"
651                 "\n", i, i*4, data[i],ntohl(data[i]));
652     }
653 }
654
655
Note: See TracBrowser for help on using the browser.