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