]>
Commit | Line | Data |
---|---|---|
30a4f2a8 | 1 | /* |
262a0e14 | 2 | * $Id$ |
30a4f2a8 | 3 | * |
4 | * DEBUG: section 0 Debug Routines | |
5 | * AUTHOR: Harvest Derived | |
6 | * | |
2b6662ba | 7 | * SQUID Web Proxy Cache http://www.squid-cache.org/ |
e25c139f | 8 | * ---------------------------------------------------------- |
30a4f2a8 | 9 | * |
2b6662ba | 10 | * Squid is the result of efforts by numerous individuals from |
11 | * the Internet community; see the CONTRIBUTORS file for full | |
12 | * details. Many organizations have provided support for Squid's | |
13 | * development; see the SPONSORS file for full details. Squid is | |
14 | * Copyrighted (C) 2001 by the Regents of the University of | |
15 | * California; see the COPYRIGHT file for full details. Squid | |
16 | * incorporates software developed and/or copyrighted by other | |
17 | * sources; see the CREDITS file for full details. | |
30a4f2a8 | 18 | * |
19 | * This program is free software; you can redistribute it and/or modify | |
20 | * it under the terms of the GNU General Public License as published by | |
21 | * the Free Software Foundation; either version 2 of the License, or | |
22 | * (at your option) any later version. | |
26ac0430 | 23 | * |
30a4f2a8 | 24 | * This program is distributed in the hope that it will be useful, |
25 | * but WITHOUT ANY WARRANTY; without even the implied warranty of | |
26 | * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the | |
27 | * GNU General Public License for more details. | |
26ac0430 | 28 | * |
30a4f2a8 | 29 | * You should have received a copy of the GNU General Public License |
30 | * along with this program; if not, write to the Free Software | |
cbdec147 | 31 | * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111, USA. |
e25c139f | 32 | * |
30a4f2a8 | 33 | */ |
5b6f3fe5 | 34 | |
351e769c | 35 | #include "config.h" |
ebe96adf | 36 | #include "Debug.h" |
608391f4 | 37 | #include "SquidTime.h" |
c772f001 | 38 | |
e1f7507e AJ |
39 | /* for Config */ |
40 | #include "structs.h" | |
41 | ||
c772f001 | 42 | int Debug::Levels[MAX_DEBUG_SECTIONS]; |
43 | int Debug::level; | |
f76d2f97 | 44 | FILE *debug_log = NULL; |
090089c4 | 45 | static char *debug_log_file = NULL; |
123abbe1 | 46 | static int Ctx_Lock = 0; |
12858c3a | 47 | static const char *debugLogTime(void); |
2d72d4fd | 48 | static void ctx_print(void); |
811ef305 | 49 | #if HAVE_SYSLOG |
5e6d4736 | 50 | #ifdef LOG_LOCAL4 |
51 | static int syslog_facility = 0; | |
52 | #endif | |
811ef305 | 53 | static void _db_print_syslog(const char *format, va_list args); |
54 | #endif | |
55 | static void _db_print_stderr(const char *format, va_list args); | |
56 | static void _db_print_file(const char *format, va_list args); | |
24382924 | 57 | |
1bc874d7 | 58 | #ifdef _SQUID_MSWIN_ |
59 | SQUIDCEXTERN LPCRITICAL_SECTION dbg_mutex; | |
60 | typedef BOOL (WINAPI * PFInitializeCriticalSectionAndSpinCount) (LPCRITICAL_SECTION, DWORD); | |
1bc874d7 | 61 | #endif |
62 | ||
b8d8561b | 63 | void |
a3d5953d | 64 | _db_print(const char *format,...) |
090089c4 | 65 | { |
95d659f0 | 66 | LOCAL_ARRAY(char, f, BUFSIZ); |
cd11dce6 | 67 | va_list args1; |
cd11dce6 | 68 | va_list args2; |
69 | va_list args3; | |
8d707f3d | 70 | |
1bc874d7 | 71 | #ifdef _SQUID_MSWIN_ |
72 | /* Multiple WIN32 threads may call this simultaneously */ | |
73 | ||
26ac0430 | 74 | if (!dbg_mutex) { |
1bc874d7 | 75 | HMODULE krnl_lib = GetModuleHandle("Kernel32"); |
76 | PFInitializeCriticalSectionAndSpinCount InitializeCriticalSectionAndSpinCount = NULL; | |
77 | ||
78 | if (krnl_lib) | |
79 | InitializeCriticalSectionAndSpinCount = | |
80 | (PFInitializeCriticalSectionAndSpinCount) GetProcAddress(krnl_lib, | |
81 | "InitializeCriticalSectionAndSpinCount"); | |
82 | ||
83 | dbg_mutex = static_cast<CRITICAL_SECTION*>(xcalloc(1, sizeof(CRITICAL_SECTION))); | |
84 | ||
85 | if (InitializeCriticalSectionAndSpinCount) { | |
86 | /* let multiprocessor systems EnterCriticalSection() fast */ | |
87 | ||
88 | if (!InitializeCriticalSectionAndSpinCount(dbg_mutex, 4000)) { | |
89 | if (debug_log) { | |
90 | fprintf(debug_log, "FATAL: _db_print: can't initialize critical section\n"); | |
91 | fflush(debug_log); | |
92 | } | |
93 | ||
94 | fprintf(stderr, "FATAL: _db_print: can't initialize critical section\n"); | |
95 | abort(); | |
96 | } else | |
97 | InitializeCriticalSection(dbg_mutex); | |
98 | } | |
99 | } | |
100 | ||
101 | EnterCriticalSection(dbg_mutex); | |
380de6f3 | 102 | #endif |
62e76326 | 103 | |
8d707f3d | 104 | /* give a chance to context-based debugging to print current context */ |
380de6f3 | 105 | if (!Ctx_Lock) |
62e76326 | 106 | ctx_print(); |
107 | ||
cd11dce6 | 108 | va_start(args1, format); |
109 | va_start(args2, format); | |
110 | va_start(args3, format); | |
62e76326 | 111 | |
811ef305 | 112 | snprintf(f, BUFSIZ, "%s| %s", |
12858c3a | 113 | debugLogTime(), |
62e76326 | 114 | format); |
115 | ||
cd11dce6 | 116 | _db_print_file(f, args1); |
117 | _db_print_stderr(f, args2); | |
62e76326 | 118 | |
811ef305 | 119 | #if HAVE_SYSLOG |
cd11dce6 | 120 | _db_print_syslog(format, args3); |
121 | #endif | |
1bc874d7 | 122 | |
8d707f3d | 123 | #ifdef _SQUID_MSWIN_ |
1bc874d7 | 124 | LeaveCriticalSection(dbg_mutex); |
1bc874d7 | 125 | #endif |
62e76326 | 126 | |
cd11dce6 | 127 | va_end(args1); |
cd11dce6 | 128 | va_end(args2); |
129 | va_end(args3); | |
811ef305 | 130 | } |
74946a0f | 131 | |
811ef305 | 132 | static void |
62e76326 | 133 | _db_print_file(const char *format, va_list args) { |
74946a0f | 134 | if (debug_log == NULL) |
62e76326 | 135 | return; |
136 | ||
123abbe1 | 137 | /* give a chance to context-based debugging to print current context */ |
138 | if (!Ctx_Lock) | |
62e76326 | 139 | ctx_print(); |
140 | ||
811ef305 | 141 | vfprintf(debug_log, format, args); |
62e76326 | 142 | |
cc192b50 | 143 | //*AYJ:*/ if (!Config.onoff.buffered_logs) |
26ac0430 | 144 | fflush(debug_log); |
090089c4 | 145 | } |
146 | ||
811ef305 | 147 | static void |
62e76326 | 148 | _db_print_stderr(const char *format, va_list args) { |
c772f001 | 149 | if (opt_debug_stderr < Debug::level) |
62e76326 | 150 | return; |
151 | ||
811ef305 | 152 | if (debug_log == stderr) |
62e76326 | 153 | return; |
154 | ||
811ef305 | 155 | vfprintf(stderr, format, args); |
156 | } | |
157 | ||
158 | #if HAVE_SYSLOG | |
159 | static void | |
62e76326 | 160 | _db_print_syslog(const char *format, va_list args) { |
811ef305 | 161 | LOCAL_ARRAY(char, tmpbuf, BUFSIZ); |
162 | /* level 0,1 go to syslog */ | |
62e76326 | 163 | |
c772f001 | 164 | if (Debug::level > 1) |
62e76326 | 165 | return; |
166 | ||
811ef305 | 167 | if (0 == opt_syslog_enable) |
62e76326 | 168 | return; |
169 | ||
811ef305 | 170 | tmpbuf[0] = '\0'; |
62e76326 | 171 | |
811ef305 | 172 | vsnprintf(tmpbuf, BUFSIZ, format, args); |
62e76326 | 173 | |
811ef305 | 174 | tmpbuf[BUFSIZ - 1] = '\0'; |
62e76326 | 175 | |
c772f001 | 176 | syslog(Debug::level == 0 ? LOG_WARNING : LOG_NOTICE, "%s", tmpbuf); |
811ef305 | 177 | } |
62e76326 | 178 | |
811ef305 | 179 | #endif /* HAVE_SYSLOG */ |
180 | ||
b8d8561b | 181 | static void |
62e76326 | 182 | debugArg(const char *arg) { |
c9f06944 | 183 | int s = 0; |
184 | int l = 0; | |
185 | int i; | |
62e76326 | 186 | |
c9f06944 | 187 | if (!strncasecmp(arg, "ALL", 3)) { |
62e76326 | 188 | s = -1; |
189 | arg += 4; | |
c9f06944 | 190 | } else { |
62e76326 | 191 | s = atoi(arg); |
192 | ||
3d0ac046 | 193 | while (*arg && *arg++ != ','); |
c9f06944 | 194 | } |
62e76326 | 195 | |
c9f06944 | 196 | l = atoi(arg); |
b6a2f15e | 197 | assert(s >= -1); |
e879923e | 198 | |
26ac0430 | 199 | if (s >= MAX_DEBUG_SECTIONS) |
e879923e | 200 | s = MAX_DEBUG_SECTIONS-1; |
62e76326 | 201 | |
b6a2f15e | 202 | if (l < 0) |
62e76326 | 203 | l = 0; |
204 | ||
b6a2f15e | 205 | if (l > 10) |
62e76326 | 206 | l = 10; |
207 | ||
c9f06944 | 208 | if (s >= 0) { |
62e76326 | 209 | Debug::Levels[s] = l; |
210 | return; | |
c9f06944 | 211 | } |
62e76326 | 212 | |
c9f06944 | 213 | for (i = 0; i < MAX_DEBUG_SECTIONS; i++) |
62e76326 | 214 | Debug::Levels[i] = l; |
12b9e9b1 | 215 | } |
216 | ||
b8d8561b | 217 | static void |
62e76326 | 218 | debugOpenLog(const char *logfile) { |
ccff9601 | 219 | if (logfile == NULL) { |
62e76326 | 220 | debug_log = stderr; |
221 | return; | |
ccff9601 | 222 | } |
62e76326 | 223 | |
ccff9601 | 224 | if (debug_log_file) |
62e76326 | 225 | xfree(debug_log_file); |
226 | ||
ccff9601 | 227 | debug_log_file = xstrdup(logfile); /* keep a static copy */ |
62e76326 | 228 | |
f2cc1af5 | 229 | if (debug_log && debug_log != stderr) |
62e76326 | 230 | fclose(debug_log); |
231 | ||
ccff9601 | 232 | debug_log = fopen(logfile, "a+"); |
62e76326 | 233 | |
ccff9601 | 234 | if (!debug_log) { |
62e76326 | 235 | fprintf(stderr, "WARNING: Cannot write log file: %s\n", logfile); |
236 | perror(logfile); | |
237 | fprintf(stderr, " messages will be sent to 'stderr'.\n"); | |
238 | fflush(stderr); | |
239 | debug_log = stderr; | |
ccff9601 | 240 | } |
62e76326 | 241 | |
ec4daaa5 | 242 | #ifdef _SQUID_WIN32_ |
c4aefe96 | 243 | setmode(fileno(debug_log), O_TEXT); |
62e76326 | 244 | |
c4aefe96 | 245 | #endif |
ccff9601 | 246 | } |
247 | ||
5e6d4736 | 248 | #if HAVE_SYSLOG |
249 | #ifdef LOG_LOCAL4 | |
250 | ||
251 | static struct syslog_facility_name { | |
252 | const char *name; | |
253 | int facility; | |
254 | } | |
255 | ||
256 | syslog_facility_names[] = { | |
257 | ||
258 | #ifdef LOG_AUTH | |
26ac0430 AJ |
259 | { |
260 | "auth", LOG_AUTH | |
261 | }, | |
5e6d4736 | 262 | #endif |
263 | #ifdef LOG_AUTHPRIV | |
26ac0430 AJ |
264 | { |
265 | "authpriv", LOG_AUTHPRIV | |
266 | }, | |
5e6d4736 | 267 | #endif |
268 | #ifdef LOG_CRON | |
26ac0430 AJ |
269 | { |
270 | "cron", LOG_CRON | |
271 | }, | |
5e6d4736 | 272 | #endif |
273 | #ifdef LOG_DAEMON | |
26ac0430 AJ |
274 | { |
275 | "daemon", LOG_DAEMON | |
276 | }, | |
5e6d4736 | 277 | #endif |
278 | #ifdef LOG_FTP | |
26ac0430 AJ |
279 | { |
280 | "ftp", LOG_FTP | |
281 | }, | |
5e6d4736 | 282 | #endif |
283 | #ifdef LOG_KERN | |
26ac0430 AJ |
284 | { |
285 | "kern", LOG_KERN | |
286 | }, | |
5e6d4736 | 287 | #endif |
288 | #ifdef LOG_LPR | |
26ac0430 AJ |
289 | { |
290 | "lpr", LOG_LPR | |
291 | }, | |
5e6d4736 | 292 | #endif |
293 | #ifdef LOG_MAIL | |
26ac0430 AJ |
294 | { |
295 | "mail", LOG_MAIL | |
296 | }, | |
5e6d4736 | 297 | #endif |
298 | #ifdef LOG_NEWS | |
26ac0430 AJ |
299 | { |
300 | "news", LOG_NEWS | |
301 | }, | |
5e6d4736 | 302 | #endif |
303 | #ifdef LOG_SYSLOG | |
26ac0430 AJ |
304 | { |
305 | "syslog", LOG_SYSLOG | |
306 | }, | |
5e6d4736 | 307 | #endif |
308 | #ifdef LOG_USER | |
26ac0430 AJ |
309 | { |
310 | "user", LOG_USER | |
311 | }, | |
5e6d4736 | 312 | #endif |
313 | #ifdef LOG_UUCP | |
26ac0430 AJ |
314 | { |
315 | "uucp", LOG_UUCP | |
316 | }, | |
5e6d4736 | 317 | #endif |
318 | #ifdef LOG_LOCAL0 | |
26ac0430 AJ |
319 | { |
320 | "local0", LOG_LOCAL0 | |
321 | }, | |
5e6d4736 | 322 | #endif |
323 | #ifdef LOG_LOCAL1 | |
26ac0430 AJ |
324 | { |
325 | "local1", LOG_LOCAL1 | |
326 | }, | |
5e6d4736 | 327 | #endif |
328 | #ifdef LOG_LOCAL2 | |
26ac0430 AJ |
329 | { |
330 | "local2", LOG_LOCAL2 | |
331 | }, | |
5e6d4736 | 332 | #endif |
333 | #ifdef LOG_LOCAL3 | |
26ac0430 AJ |
334 | { |
335 | "local3", LOG_LOCAL3 | |
336 | }, | |
5e6d4736 | 337 | #endif |
338 | #ifdef LOG_LOCAL4 | |
26ac0430 AJ |
339 | { |
340 | "local4", LOG_LOCAL4 | |
341 | }, | |
5e6d4736 | 342 | #endif |
343 | #ifdef LOG_LOCAL5 | |
26ac0430 AJ |
344 | { |
345 | "local5", LOG_LOCAL5 | |
346 | }, | |
5e6d4736 | 347 | #endif |
348 | #ifdef LOG_LOCAL6 | |
26ac0430 AJ |
349 | { |
350 | "local6", LOG_LOCAL6 | |
351 | }, | |
5e6d4736 | 352 | #endif |
353 | #ifdef LOG_LOCAL7 | |
26ac0430 AJ |
354 | { |
355 | "local7", LOG_LOCAL7 | |
356 | }, | |
5e6d4736 | 357 | #endif |
26ac0430 AJ |
358 | { |
359 | NULL, 0 | |
360 | } | |
361 | }; | |
5e6d4736 | 362 | |
363 | #endif | |
364 | ||
365 | void | |
366 | _db_set_syslog(const char *facility) { | |
367 | opt_syslog_enable = 1; | |
368 | #ifdef LOG_LOCAL4 | |
369 | #ifdef LOG_DAEMON | |
370 | ||
371 | syslog_facility = LOG_DAEMON; | |
372 | #else | |
373 | ||
374 | syslog_facility = LOG_LOCAL4; | |
375 | #endif | |
376 | ||
377 | if (facility) { | |
378 | ||
379 | struct syslog_facility_name *n; | |
380 | ||
381 | for (n = syslog_facility_names; n->name; n++) { | |
382 | if (strcmp(n->name, facility) == 0) { | |
383 | syslog_facility = n->facility; | |
384 | return; | |
385 | } | |
386 | } | |
387 | ||
388 | fprintf(stderr, "unknown syslog facility '%s'\n", facility); | |
389 | exit(1); | |
390 | } | |
391 | ||
392 | #else | |
393 | if (facility) | |
394 | fprintf(stderr, "syslog facility type not supported on your system\n"); | |
395 | ||
396 | #endif | |
397 | } | |
398 | ||
399 | #endif | |
400 | ||
b8d8561b | 401 | void |
d9e04dc7 | 402 | Debug::parseOptions(char const *options) { |
12b9e9b1 | 403 | int i; |
404 | char *p = NULL; | |
405 | char *s = NULL; | |
090089c4 | 406 | |
26ac0430 | 407 | if (Config.onoff.debug_override_X) { |
37296f4c | 408 | debugs(0, 9, "command-line -X overrides: " << options); |
409 | return; | |
410 | } | |
411 | ||
12b9e9b1 | 412 | for (i = 0; i < MAX_DEBUG_SECTIONS; i++) |
fb6a61d1 | 413 | Debug::Levels[i] = 0; |
090089c4 | 414 | |
30a4f2a8 | 415 | if (options) { |
62e76326 | 416 | p = xstrdup(options); |
417 | ||
418 | for (s = strtok(p, w_space); s; s = strtok(NULL, w_space)) | |
419 | debugArg(s); | |
420 | ||
421 | xfree(p); | |
12b9e9b1 | 422 | } |
d9e04dc7 | 423 | } |
424 | ||
425 | void | |
426 | _db_init(const char *logfile, const char *options) { | |
427 | Debug::parseOptions(options); | |
62e76326 | 428 | |
ccff9601 | 429 | debugOpenLog(logfile); |
090089c4 | 430 | |
30a4f2a8 | 431 | #if HAVE_SYSLOG && defined(LOG_LOCAL4) |
62e76326 | 432 | |
6e40f263 | 433 | if (opt_syslog_enable) |
7dbca7a4 | 434 | openlog(APP_SHORTNAME, LOG_PID | LOG_NDELAY | LOG_CONS, syslog_facility); |
62e76326 | 435 | |
db40ae20 | 436 | #endif /* HAVE_SYSLOG */ |
437 | ||
090089c4 | 438 | } |
439 | ||
b8d8561b | 440 | void |
62e76326 | 441 | _db_rotate_log(void) { |
090089c4 | 442 | int i; |
95d659f0 | 443 | LOCAL_ARRAY(char, from, MAXPATHLEN); |
444 | LOCAL_ARRAY(char, to, MAXPATHLEN); | |
88738790 | 445 | #ifdef S_ISREG |
62e76326 | 446 | |
2edc2504 | 447 | struct stat sb; |
88738790 | 448 | #endif |
090089c4 | 449 | |
450 | if (debug_log_file == NULL) | |
62e76326 | 451 | return; |
452 | ||
71d95578 | 453 | #ifdef S_ISREG |
62e76326 | 454 | |
2edc2504 | 455 | if (stat(debug_log_file, &sb) == 0) |
62e76326 | 456 | if (S_ISREG(sb.st_mode) == 0) |
457 | return; | |
458 | ||
71d95578 | 459 | #endif |
090089c4 | 460 | |
1f38f50a | 461 | /* |
462 | * NOTE: we cannot use xrename here without having it in a | |
463 | * separate file -- tools.c has too many dependencies to be | |
464 | * used everywhere debug.c is used. | |
465 | */ | |
090089c4 | 466 | /* Rotate numbers 0 through N up one */ |
b6f794d6 | 467 | for (i = Config.Log.rotateNumber; i > 1;) { |
62e76326 | 468 | i--; |
469 | snprintf(from, MAXPATHLEN, "%s.%d", debug_log_file, i - 1); | |
470 | snprintf(to, MAXPATHLEN, "%s.%d", debug_log_file, i); | |
0ef0f1de | 471 | #ifdef _SQUID_MSWIN_ |
62e76326 | 472 | |
473 | remove | |
26ac0430 | 474 | (to); |
62e76326 | 475 | |
0ef0f1de | 476 | #endif |
62e76326 | 477 | |
478 | rename(from, to); | |
090089c4 | 479 | } |
62e76326 | 480 | |
481 | /* | |
482 | * You can't rename open files on Microsoft "operating systems" | |
483 | * so we close before renaming. | |
484 | */ | |
e24070c5 | 485 | #ifdef _SQUID_MSWIN_ |
486 | if (debug_log != stderr) | |
62e76326 | 487 | fclose(debug_log); |
488 | ||
e24070c5 | 489 | #endif |
090089c4 | 490 | /* Rotate the current log to .0 */ |
b6f794d6 | 491 | if (Config.Log.rotateNumber > 0) { |
62e76326 | 492 | snprintf(to, MAXPATHLEN, "%s.%d", debug_log_file, 0); |
0ef0f1de | 493 | #ifdef _SQUID_MSWIN_ |
62e76326 | 494 | |
495 | remove | |
26ac0430 | 496 | (to); |
62e76326 | 497 | |
0ef0f1de | 498 | #endif |
62e76326 | 499 | |
500 | rename(debug_log_file, to); | |
090089c4 | 501 | } |
62e76326 | 502 | |
090089c4 | 503 | /* Close and reopen the log. It may have been renamed "manually" |
504 | * before HUP'ing us. */ | |
0a8020d1 | 505 | if (debug_log != stderr) |
62e76326 | 506 | debugOpenLog(Config.Log.log); |
090089c4 | 507 | } |
4873d3a4 | 508 | |
509 | static const char * | |
12858c3a | 510 | debugLogTime(void) { |
511 | ||
512 | time_t t = getCurrentTime(); | |
62e76326 | 513 | |
4873d3a4 | 514 | struct tm *tm; |
515 | static char buf[128]; | |
516 | static time_t last_t = 0; | |
62e76326 | 517 | |
12858c3a | 518 | if (Debug::level > 1) { |
519 | char buf2[128]; | |
520 | tm = localtime(&t); | |
521 | strftime(buf2, 127, "%Y/%m/%d %H:%M:%S", tm); | |
522 | buf2[127] = '\0'; | |
523 | snprintf(buf, 127, "%s.%03d", buf2, (int) current_time.tv_usec / 1000); | |
524 | last_t = t; | |
525 | } else if (t != last_t) { | |
62e76326 | 526 | tm = localtime(&t); |
527 | strftime(buf, 127, "%Y/%m/%d %H:%M:%S", tm); | |
528 | last_t = t; | |
4873d3a4 | 529 | } |
62e76326 | 530 | |
12858c3a | 531 | buf[127] = '\0'; |
4873d3a4 | 532 | return buf; |
533 | } | |
534 | ||
bb71ea1f | 535 | void |
62e76326 | 536 | xassert(const char *msg, const char *file, int line) { |
bf8fe701 | 537 | debugs(0, 0, "assertion failed: " << file << ":" << line << ": \"" << msg << "\""); |
62e76326 | 538 | |
bb71ea1f | 539 | if (!shutting_down) |
62e76326 | 540 | abort(); |
bb71ea1f | 541 | } |
542 | ||
123abbe1 | 543 | /* |
544 | * Context-based Debugging | |
26970499 | 545 | * |
546 | * Rationale | |
547 | * --------- | |
26ac0430 | 548 | * |
26970499 | 549 | * When you have a long nested processing sequence, it is often impossible |
550 | * for low level routines to know in what larger context they operate. If a | |
551 | * routine coredumps, one can restore the context using debugger trace. | |
552 | * However, in many case you do not want to coredump, but just want to report | |
553 | * a potential problem. A report maybe useless out of problem context. | |
26ac0430 | 554 | * |
26970499 | 555 | * To solve this potential problem, use the following approach: |
26ac0430 | 556 | * |
26970499 | 557 | * int |
558 | * top_level_foo(const char *url) | |
559 | * { | |
560 | * // define current context | |
561 | * // note: we stack but do not dup ctx descriptions! | |
562 | * Ctx ctx = ctx_enter(url); | |
563 | * ... | |
564 | * // go down; middle_level_bar will eventually call bottom_level_boo | |
565 | * middle_level_bar(method, protocol); | |
566 | * ... | |
567 | * // exit, clean after yourself | |
568 | * ctx_exit(ctx); | |
569 | * } | |
26ac0430 | 570 | * |
26970499 | 571 | * void |
572 | * bottom_level_boo(int status, void *data) | |
573 | * { | |
574 | * // detect exceptional condition, and simply report it, the context | |
575 | * // information will be available somewhere close in the log file | |
576 | * if (status == STRANGE_STATUS) | |
bf8fe701 | 577 | * debugs(13, 6, "DOS attack detected, data: " << data); |
26970499 | 578 | * ... |
579 | * } | |
26ac0430 | 580 | * |
26970499 | 581 | * Current implementation is extremely simple but still very handy. It has a |
582 | * negligible overhead (descriptions are not duplicated). | |
26ac0430 | 583 | * |
26970499 | 584 | * When the _first_ debug message for a given context is printed, it is |
585 | * prepended with the current context description. Context is printed with | |
586 | * the same debugging level as the original message. | |
26ac0430 | 587 | * |
26970499 | 588 | * Note that we do not print context every type you do ctx_enter(). This |
589 | * approach would produce too many useless messages. For the same reason, a | |
590 | * context description is printed at most _once_ even if you have 10 | |
591 | * debugging messages within one context. | |
26ac0430 | 592 | * |
26970499 | 593 | * Contexts can be nested, of course. You must use ctx_enter() to enter a |
594 | * context (push it onto stack). It is probably safe to exit several nested | |
595 | * contexts at _once_ by calling ctx_exit() at the top level (this will pop | |
596 | * all context till current one). However, as in any stack, you cannot start | |
597 | * in the middle. | |
26ac0430 AJ |
598 | * |
599 | * Analysis: | |
26970499 | 600 | * i) locate debugging message, |
601 | * ii) locate current context by going _upstream_ in your log file, | |
602 | * iii) hack away. | |
603 | * | |
604 | * | |
26ac0430 | 605 | * To-Do: |
26970499 | 606 | * ----- |
607 | * | |
123abbe1 | 608 | * decide if we want to dup() descriptions (adds overhead) but allows to |
609 | * add printf()-style interface | |
26970499 | 610 | * |
2ac76861 | 611 | * implementation: |
26970499 | 612 | * --------------- |
2ac76861 | 613 | * |
123abbe1 | 614 | * descriptions for contexts over CTX_MAX_LEVEL limit are ignored, you probably |
615 | * have a bug if your nesting goes that deep. | |
616 | */ | |
2ac76861 | 617 | |
123abbe1 | 618 | #define CTX_MAX_LEVEL 255 |
2ac76861 | 619 | |
620 | /* | |
621 | * produce a warning when nesting reaches this level and then double | |
622 | * the level | |
623 | */ | |
624 | static int Ctx_Warn_Level = 32; | |
123abbe1 | 625 | /* all descriptions has been printed up to this level */ |
a3f9588e | 626 | static int Ctx_Reported_Level = -1; |
123abbe1 | 627 | /* descriptions are still valid or active up to this level */ |
a3f9588e | 628 | static int Ctx_Valid_Level = -1; |
123abbe1 | 629 | /* current level, the number of nested ctx_enter() calls */ |
a3f9588e | 630 | static int Ctx_Current_Level = -1; |
123abbe1 | 631 | /* saved descriptions (stack) */ |
2ac76861 | 632 | static const char *Ctx_Descrs[CTX_MAX_LEVEL + 1]; |
b70d1c58 | 633 | /* "safe" get secription */ |
634 | static const char *ctx_get_descr(Ctx ctx); | |
123abbe1 | 635 | |
636 | ||
637 | Ctx | |
62e76326 | 638 | ctx_enter(const char *descr) { |
123abbe1 | 639 | Ctx_Current_Level++; |
640 | ||
641 | if (Ctx_Current_Level <= CTX_MAX_LEVEL) | |
62e76326 | 642 | Ctx_Descrs[Ctx_Current_Level] = descr; |
123abbe1 | 643 | |
644 | if (Ctx_Current_Level == Ctx_Warn_Level) { | |
bf8fe701 | 645 | debugs(0, 0, "# ctx: suspiciously deep (" << Ctx_Warn_Level << ") nesting:"); |
62e76326 | 646 | Ctx_Warn_Level *= 2; |
123abbe1 | 647 | } |
62e76326 | 648 | |
123abbe1 | 649 | return Ctx_Current_Level; |
650 | } | |
651 | ||
652 | void | |
62e76326 | 653 | ctx_exit(Ctx ctx) { |
123abbe1 | 654 | assert(ctx >= 0); |
2ac76861 | 655 | Ctx_Current_Level = (ctx >= 0) ? ctx - 1 : -1; |
62e76326 | 656 | |
123abbe1 | 657 | if (Ctx_Valid_Level > Ctx_Current_Level) |
62e76326 | 658 | Ctx_Valid_Level = Ctx_Current_Level; |
123abbe1 | 659 | } |
660 | ||
661 | /* | |
662 | * the idea id to print each context description at most once but provide enough | |
663 | * info for deducing the current execution stack | |
664 | */ | |
665 | static void | |
62e76326 | 666 | ctx_print(void) { |
123abbe1 | 667 | /* lock so _db_print will not call us recursively */ |
668 | Ctx_Lock++; | |
669 | /* ok, user saw [0,Ctx_Reported_Level] descriptions */ | |
670 | /* first inform about entries popped since user saw them */ | |
62e76326 | 671 | |
123abbe1 | 672 | if (Ctx_Valid_Level < Ctx_Reported_Level) { |
62e76326 | 673 | if (Ctx_Reported_Level != Ctx_Valid_Level + 1) |
674 | _db_print("ctx: exit levels from %2d down to %2d\n", | |
675 | Ctx_Reported_Level, Ctx_Valid_Level + 1); | |
676 | else | |
677 | _db_print("ctx: exit level %2d\n", Ctx_Reported_Level); | |
678 | ||
679 | Ctx_Reported_Level = Ctx_Valid_Level; | |
123abbe1 | 680 | } |
62e76326 | 681 | |
123abbe1 | 682 | /* report new contexts that were pushed since last report */ |
683 | while (Ctx_Reported_Level < Ctx_Current_Level) { | |
62e76326 | 684 | Ctx_Reported_Level++; |
685 | Ctx_Valid_Level++; | |
686 | _db_print("ctx: enter level %2d: '%s'\n", Ctx_Reported_Level, | |
687 | ctx_get_descr(Ctx_Reported_Level)); | |
123abbe1 | 688 | } |
62e76326 | 689 | |
123abbe1 | 690 | /* unlock */ |
691 | Ctx_Lock--; | |
692 | } | |
b70d1c58 | 693 | |
694 | /* checks for nulls and overflows */ | |
695 | static const char * | |
62e76326 | 696 | ctx_get_descr(Ctx ctx) { |
2ac76861 | 697 | if (ctx < 0 || ctx > CTX_MAX_LEVEL) |
62e76326 | 698 | return "<lost>"; |
699 | ||
b70d1c58 | 700 | return Ctx_Descrs[ctx] ? Ctx_Descrs[ctx] : "<null>"; |
701 | } | |
f95fe6ed | 702 | |
9eab365d | 703 | int Debug::TheDepth = 0; |
704 | ||
f95fe6ed | 705 | std::ostream & |
706 | Debug::getDebugOut() { | |
9eab365d | 707 | assert(TheDepth >= 0); |
708 | ++TheDepth; | |
709 | if (TheDepth > 1) { | |
710 | assert(CurrentDebug); | |
711 | *CurrentDebug << std::endl << "reentrant debuging " << TheDepth << "-{"; | |
712 | } else { | |
713 | assert(!CurrentDebug); | |
714 | CurrentDebug = new std::ostringstream(); | |
715 | // set default formatting flags | |
716 | CurrentDebug->setf(std::ios::fixed); | |
717 | CurrentDebug->precision(2); | |
718 | } | |
4ecaa0f0 | 719 | return *CurrentDebug; |
f95fe6ed | 720 | } |
721 | ||
722 | void | |
723 | Debug::finishDebug() { | |
9eab365d | 724 | assert(TheDepth >= 0); |
725 | assert(CurrentDebug); | |
726 | if (TheDepth > 1) { | |
727 | *CurrentDebug << "}-" << TheDepth << std::endl; | |
728 | } else { | |
729 | assert(TheDepth == 1); | |
730 | _db_print("%s\n", CurrentDebug->str().c_str()); | |
731 | delete CurrentDebug; | |
732 | CurrentDebug = NULL; | |
733 | } | |
734 | --TheDepth; | |
735 | } | |
736 | ||
737 | // Hack: replaces global ::xassert() to debug debugging assertions | |
738 | // Relies on assert macro calling xassert() without a specific scope. | |
739 | void | |
740 | Debug::xassert(const char *msg, const char *file, int line) { | |
26ac0430 | 741 | |
9eab365d | 742 | if (CurrentDebug) { |
743 | *CurrentDebug << "assertion failed: " << file << ":" << line << | |
26ac0430 | 744 | ": \"" << msg << "\""; |
9eab365d | 745 | } |
746 | abort(); | |
f95fe6ed | 747 | } |
748 | ||
bf5113eb | 749 | std::ostringstream (*Debug::CurrentDebug)(NULL); |
5b6f3fe5 | 750 | |
af28bfbd AJ |
751 | const size_t |
752 | BuildPrefixInit() | |
5b6f3fe5 | 753 | { |
cd31e896 | 754 | // XXX: This must be kept in sync with the actual debug.cc location |
af28bfbd AJ |
755 | const char *ThisFileNameTail = "src/debug.cc"; |
756 | ||
5b6f3fe5 | 757 | const char *file=__FILE__; |
cd31e896 AR |
758 | |
759 | // Disable heuristic if it does not work. | |
760 | if (!strstr(file, ThisFileNameTail)) | |
761 | return 0; | |
762 | ||
af28bfbd | 763 | return strlen(file)-strlen(ThisFileNameTail); |
5b6f3fe5 | 764 | } |
af28bfbd AJ |
765 | |
766 | const char* | |
767 | SkipBuildPrefix(const char* path) | |
5b6f3fe5 | 768 | { |
af28bfbd AJ |
769 | static const size_t BuildPrefixLength = BuildPrefixInit(); |
770 | ||
5b6f3fe5 FC |
771 | return path+BuildPrefixLength; |
772 | } |