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 |
|
---|