root/trunk/libffado/src/debugmodule/debugmodule.cpp

Revision 587, 13.6 kB (checked in by ppalmers, 14 years ago)

- moved all vendor id's to one include file
- introduced the framework for the ECHO FireWorks? platform

  • 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     if ( level > m_level ) {
87         return;
88     }
89
90     va_list arg;
91
92     va_start( arg, format );
93
94     DebugModuleManager::instance()->va_print( format, arg );
95
96     va_end( arg );
97 }
98
99 void
100 DebugModule::print( debug_level_t level,
101                     const char*   file,
102                     const char*   function,
103                     unsigned int  line,
104                     const char*   format,
105                     ... ) const
106 {
107     if ( level > m_level ) {
108         return;
109     }
110
111     va_list arg;
112     va_start( arg, format );
113
114     // remove the path info from the filename
115     const char *f = file;
116     const char *fname = file;
117     while((f=strstr(f, "/"))) {
118         f++; // move away from delimiter
119         fname=f;
120     }
121    
122     // add a timing timestamp
123     struct timespec ts;
124     clock_gettime(CLOCK_MONOTONIC, &ts);
125     uint32_t ts_usec=(uint32_t)(ts.tv_sec * 1000000LL + ts.tv_nsec / 1000LL);
126    
127     DebugModuleManager::instance()->print( "%010lu: %s (%s)[%4d] %s: ",
128                  ts_usec, getPreSequence( level ),
129                  fname,  line,  function );
130     DebugModuleManager::instance()->va_print( format, arg );
131     DebugModuleManager::instance()->print( "%s", getPostSequence( level ) );
132     va_end( arg );
133 }
134
135 const char*
136 DebugModule::getPreSequence( debug_level_t level ) const
137 {
138     if ( ( level <= eDL_Normal ) && ( level >= eDL_Fatal ) ) {
139         return colorTable[level].preSequence;
140     }
141     return colorTable[eDL_Normal].preSequence;
142 }
143
144 const char*
145 DebugModule::getPostSequence( debug_level_t level ) const
146 {
147     if ( ( level <= eDL_Normal ) && ( level >= eDL_Fatal ) ) {
148         return colorTable[level].postSequence;
149     }
150     return colorTable[eDL_Normal].postSequence;
151 }
152
153 //--------------------------------------
154
155 DebugModuleManager* DebugModuleManager::m_instance = 0;
156
157 DebugModuleManager::DebugModuleManager()
158     : mb_initialized(0)
159     , mb_inbuffer(0)
160     , mb_outbuffer(0)
161     , mb_overruns(0)
162
163 {
164
165 }
166
167 DebugModuleManager::~DebugModuleManager()
168 {
169     // cleanin up leftover modules
170     for ( DebugModuleVectorIterator it = m_debugModules.begin();
171           it != m_debugModules.end();
172           ++it )
173     {
174         fprintf(stderr,"Cleaning up leftover debug module: %s\n",(*it)->getName().c_str());
175         m_debugModules.erase( it );
176         delete *it;
177     }
178
179     if (!mb_initialized)
180         return;
181
182     pthread_mutex_lock(&mb_write_lock);
183     mb_initialized = 0;
184     pthread_cond_signal(&mb_ready_cond);
185     pthread_mutex_unlock(&mb_write_lock);
186
187     pthread_join(mb_writer_thread, NULL);
188     mb_flush();
189
190     if (mb_overruns)
191         fprintf(stderr, "WARNING: %d message buffer overruns!\n",
192             mb_overruns);
193     else
194         fprintf(stderr, "no message buffer overruns\n");
195
196     pthread_mutex_destroy(&mb_write_lock);
197     pthread_cond_destroy(&mb_ready_cond);
198
199 }
200
201 bool
202 DebugModuleManager::init()
203 {
204     if (mb_initialized)
205         return true;
206
207         // if ( m_level >= eDL_VeryVerbose )
208         //         cout << "DebugModuleManager init..." << endl;
209
210     pthread_mutex_init(&mb_write_lock, NULL);
211     pthread_mutex_init(&mb_flush_lock, NULL);
212     pthread_cond_init(&mb_ready_cond, NULL);
213
214      mb_overruns = 0;
215      mb_initialized = 1;
216
217     if (pthread_create(&mb_writer_thread, NULL, &mb_thread_func, (void *)this) != 0)
218          mb_initialized = 0;
219
220     return true;
221 }
222
223 DebugModuleManager*
224 DebugModuleManager::instance()
225 {
226     if ( !m_instance ) {
227         m_instance = new DebugModuleManager;
228         if ( !m_instance ) {
229             cerr << "DebugModuleManager::instance Failed to create "
230                  << "DebugModuleManager" << endl;
231         }
232         if ( !m_instance->init() ) {
233             cerr << "DebugModuleManager::instance Failed to init "
234                  << "DebugModuleManager" << endl;
235         }
236     }
237     return m_instance;
238 }
239
240 bool
241 DebugModuleManager::registerModule( DebugModule& debugModule )
242 {
243     bool already_present=false;
244
245     for ( DebugModuleVectorIterator it = m_debugModules.begin();
246           it != m_debugModules.end();
247           ++it )
248     {
249         if ( *it == &debugModule ) {
250             already_present=true;
251             return true;
252         }
253     }
254
255     if (already_present) {
256         cerr << "DebugModuleManager::registerModule: Module already registered: "
257             << "DebugModule (" << debugModule.getName() << ")" << endl;
258     } else {
259         m_debugModules.push_back( &debugModule );
260     }
261     return true;
262 }
263
264 bool
265 DebugModuleManager::unregisterModule( DebugModule& debugModule )
266 {
267
268     for ( DebugModuleVectorIterator it = m_debugModules.begin();
269           it != m_debugModules.end();
270           ++it )
271     {
272         if ( *it == &debugModule ) {
273             m_debugModules.erase( it );
274             return true;
275         }
276     }
277
278     cerr << "DebugModuleManager::unregisterModule: Could not unregister "
279          << "DebugModule (" << debugModule.getName() << ")" << endl;
280     return false;
281 }
282
283 bool
284 DebugModuleManager::setMgrDebugLevel( std::string name, debug_level_t level )
285 {
286     for ( DebugModuleVectorIterator it = m_debugModules.begin();
287           it != m_debugModules.end();
288           ++it )
289     {
290         if ( (*it)->getName() == name ) {
291             return (*it)->setLevel( level );
292         }
293     }
294
295     cerr << "setDebugLevel: Did not find DebugModule ("
296          << name << ")" << endl;
297     return false;
298 }
299
300 void
301 DebugModuleManager::flush()
302 {
303 //     mb_flush();
304 }
305
306 void
307 DebugModuleManager::mb_flush()
308 {
309     /* called WITHOUT the mb_write_lock */
310    
311     /* the flush lock is to allow a flush from multiple threads
312      * this allows a code section that outputs a lot of debug messages
313      * and that can be blocked to flush the buffer itself such that it
314      * does not overflow.
315      */
316     DebugModuleManager *m=DebugModuleManager::instance();
317     pthread_mutex_lock(&m->mb_flush_lock);
318     while (mb_outbuffer != mb_inbuffer) {
319         fputs(mb_buffers[mb_outbuffer], stderr);
320         mb_outbuffer = MB_NEXT(mb_outbuffer);
321     }
322     pthread_mutex_unlock(&m->mb_flush_lock);
323 }
324
325 void *
326 DebugModuleManager::mb_thread_func(void *arg)
327 {
328
329     DebugModuleManager *m=static_cast<DebugModuleManager *>(arg);
330
331     /* The mutex is only to eliminate collisions between multiple
332      * writer threads and protect the condition variable. */
333      pthread_mutex_lock(&m->mb_write_lock);
334
335     while (m->mb_initialized) {
336          pthread_cond_wait(&m->mb_ready_cond, &m->mb_write_lock);
337
338          /* releasing the mutex reduces contention */
339          pthread_mutex_unlock(&m->mb_write_lock);
340          m->mb_flush();
341          pthread_mutex_lock(&m->mb_write_lock);
342     }
343
344      pthread_mutex_unlock(&m->mb_write_lock);
345
346     return NULL;
347 }
348
349 void
350 DebugModuleManager::print(const char *fmt, ...)
351 {
352     char msg[MB_BUFFERSIZE];
353     va_list ap;
354     unsigned int ntries=5;
355     struct timespec wait = {0,50000};
356    
357     /* format the message first, to reduce lock contention */
358     va_start(ap, fmt);
359     if (vsnprintf(msg, MB_BUFFERSIZE, fmt, ap) >= MB_BUFFERSIZE) {
360         print("WARNING: message truncated!\n");
361     }
362     va_end(ap);
363
364     if (!mb_initialized) {
365         /* Unable to print message with realtime safety.
366          * Complain and print it anyway. */
367         fprintf(stderr, "ERROR: messagebuffer not initialized: %s",
368             msg);
369         return;
370     }
371    
372 #ifdef DO_MESSAGE_BUFFER_PRINT
373     while (ntries) { // try a few times
374         if (pthread_mutex_trylock(&mb_write_lock) == 0) {
375             strncpy(mb_buffers[mb_inbuffer], msg, MB_BUFFERSIZE);
376             mb_inbuffer = MB_NEXT(mb_inbuffer);
377             pthread_cond_signal(&mb_ready_cond);
378             pthread_mutex_unlock(&mb_write_lock);
379             break;
380         } else {
381             nanosleep(&wait, NULL);
382             ntries--;
383         }
384     }
385     if (ntries==0) {  /* lock collision */
386         //         atomic_add(&mb_overruns, 1);
387         // FIXME: atomicity
388         mb_overruns++; // skip the atomicness for now
389     }
390 #else
391     fprintf(stderr,msg);
392 #endif
393 }
394
395 void
396 DebugModuleManager::va_print (const char *fmt, va_list ap)
397 {
398     char msg[MB_BUFFERSIZE];
399     unsigned int ntries=5;
400     struct timespec wait = {0,50000};
401
402     /* format the message first, to reduce lock contention */
403     if (vsnprintf(msg, MB_BUFFERSIZE, fmt, ap) >= MB_BUFFERSIZE) {
404         print("WARNING: message truncated!\n");
405     }
406    
407     if (!mb_initialized) {
408         /* Unable to print message with realtime safety.
409          * Complain and print it anyway. */
410         fprintf(stderr, "ERROR: messagebuffer not initialized: %s",
411             msg);
412         return;
413     }
414    
415 #ifdef DO_MESSAGE_BUFFER_PRINT
416     while (ntries) { // try a few times
417         if (pthread_mutex_trylock(&mb_write_lock) == 0) {
418             strncpy(mb_buffers[mb_inbuffer], msg, MB_BUFFERSIZE);
419             mb_inbuffer = MB_NEXT(mb_inbuffer);
420             pthread_cond_signal(&mb_ready_cond);
421             pthread_mutex_unlock(&mb_write_lock);
422             break;
423         } else {
424             nanosleep(&wait, NULL);
425             ntries--;
426         }
427     }
428    
429     if (ntries==0) {  /* lock collision */
430 //         atomic_add(&mb_overruns, 1);
431         // FIXME: atomicity
432         mb_overruns++; // skip the atomicness for now
433     }
434 #else
435     fprintf(stderr,msg);
436 #endif
437 }
438
439 //----------------------------------------
440
441 unsigned char
442 toAscii( unsigned char c )
443 {
444     if ( ( c > 31 ) && ( c < 126) ) {
445         return c;
446     } else {
447         return '.';
448     }
449 }
450
451 /* converts a quadlet to a uchar * buffer
452  * not implemented optimally, but clear
453  */
454 void
455 quadlet2char( quadlet_t quadlet, unsigned char* buff )
456 {
457     *(buff)   = (quadlet>>24)&0xFF;
458     *(buff+1) = (quadlet>>16)&0xFF;
459     *(buff+2) = (quadlet>> 8)&0xFF;
460     *(buff+3) = (quadlet)    &0xFF;
461 }
462
463 void
464 hexDump( unsigned char *data_start, unsigned int length )
465 {
466     unsigned int i=0;
467     unsigned int byte_pos;
468     unsigned int bytes_left;
469
470     if ( length <= 0 ) {
471         return;
472     }
473     if ( length >= 7 ) {
474         for ( i = 0; i < (length-7); i += 8 ) {
475             printf( "%04X: %02X %02X %02X %02X %02X %02X %02X %02X "
476                     "- [%c%c%c%c%c%c%c%c]\n",
477
478                     i,
479
480                     *(data_start+i+0),
481                     *(data_start+i+1),
482                     *(data_start+i+2),
483                     *(data_start+i+3),
484                     *(data_start+i+4),
485                     *(data_start+i+5),
486                     *(data_start+i+6),
487                     *(data_start+i+7),
488
489                     toAscii( *(data_start+i+0) ),
490                     toAscii( *(data_start+i+1) ),
491                     toAscii( *(data_start+i+2) ),
492                     toAscii( *(data_start+i+3) ),
493                     toAscii( *(data_start+i+4) ),
494                     toAscii( *(data_start+i+5) ),
495                     toAscii( *(data_start+i+6) ),
496                     toAscii( *(data_start+i+7) )
497                 );
498         }
499     }
500     byte_pos = i;
501     bytes_left = length - byte_pos;
502
503     printf( "%04X:" ,i );
504     for ( i = byte_pos; i < length; i += 1 ) {
505         printf( " %02X", *(data_start+i) );
506     }
507     for ( i=0; i < 8-bytes_left; i+=1 ) {
508         printf( "   " );
509     }
510
511     printf( " - [" );
512     for ( i = byte_pos; i < length; i += 1) {
513         printf( "%c", toAscii(*(data_start+i)));
514     }
515     for ( i = 0; i < 8-bytes_left; i += 1) {
516         printf( " " );
517     }
518
519     printf( "]" );
520     printf( "\n" );
521 }
522
523 void
524 hexDumpQuadlets( quadlet_t *data, unsigned int length )
525 {
526     unsigned int i=0;
527
528     if ( length <= 0 ) {
529         return;
530     }
531     for (i = 0; i< length; i += 1) {
532         printf( "%02d %04X: %08X (%08X)"
533                 "\n", i, i*4, data[i],ntohl(data[i]));
534     }
535 }
536
537
Note: See TracBrowser for help on using the browser.