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

Revision 730, 17.2 kB (checked in by ppalmers, 16 years ago)

- Remove OSC related code
- create DBus server application
- add "scons debian" target that builds a debian package

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