]>
Commit | Line | Data |
---|---|---|
38d04788 | 1 | |
30a4f2a8 | 2 | /* |
a3f9588e | 3 | * $Id: debug.cc,v 1.65 1998/04/27 19:16:08 wessels Exp $ |
30a4f2a8 | 4 | * |
5 | * DEBUG: section 0 Debug Routines | |
6 | * AUTHOR: Harvest Derived | |
7 | * | |
42c04c16 | 8 | * SQUID Internet Object Cache http://squid.nlanr.net/Squid/ |
30a4f2a8 | 9 | * -------------------------------------------------------- |
10 | * | |
11 | * Squid is the result of efforts by numerous individuals from the | |
12 | * Internet community. Development is led by Duane Wessels of the | |
13 | * National Laboratory for Applied Network Research and funded by | |
14 | * the National Science Foundation. | |
15 | * | |
16 | * This program is free software; you can redistribute it and/or modify | |
17 | * it under the terms of the GNU General Public License as published by | |
18 | * the Free Software Foundation; either version 2 of the License, or | |
19 | * (at your option) any later version. | |
20 | * | |
21 | * This program is distributed in the hope that it will be useful, | |
22 | * but WITHOUT ANY WARRANTY; without even the implied warranty of | |
23 | * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the | |
24 | * GNU General Public License for more details. | |
25 | * | |
26 | * You should have received a copy of the GNU General Public License | |
27 | * along with this program; if not, write to the Free Software | |
28 | * Foundation, Inc., 675 Mass Ave, Cambridge, MA 02139, USA. | |
29 | * | |
30 | */ | |
899a9fca | 31 | |
30a4f2a8 | 32 | /* |
33 | * Copyright (c) 1994, 1995. All rights reserved. | |
34 | * | |
35 | * The Harvest software was developed by the Internet Research Task | |
36 | * Force Research Group on Resource Discovery (IRTF-RD): | |
37 | * | |
38 | * Mic Bowman of Transarc Corporation. | |
39 | * Peter Danzig of the University of Southern California. | |
40 | * Darren R. Hardy of the University of Colorado at Boulder. | |
41 | * Udi Manber of the University of Arizona. | |
42 | * Michael F. Schwartz of the University of Colorado at Boulder. | |
43 | * Duane Wessels of the University of Colorado at Boulder. | |
44 | * | |
45 | * This copyright notice applies to software in the Harvest | |
46 | * ``src/'' directory only. Users should consult the individual | |
47 | * copyright notices in the ``components/'' subdirectories for | |
48 | * copyright information about other software bundled with the | |
49 | * Harvest source code distribution. | |
50 | * | |
51 | * TERMS OF USE | |
52 | * | |
53 | * The Harvest software may be used and re-distributed without | |
54 | * charge, provided that the software origin and research team are | |
55 | * cited in any use of the system. Most commonly this is | |
56 | * accomplished by including a link to the Harvest Home Page | |
57 | * (http://harvest.cs.colorado.edu/) from the query page of any | |
58 | * Broker you deploy, as well as in the query result pages. These | |
59 | * links are generated automatically by the standard Broker | |
60 | * software distribution. | |
61 | * | |
62 | * The Harvest software is provided ``as is'', without express or | |
63 | * implied warranty, and with no support nor obligation to assist | |
64 | * in its use, correction, modification or enhancement. We assume | |
65 | * no liability with respect to the infringement of copyrights, | |
66 | * trade secrets, or any patents, and are not responsible for | |
67 | * consequential damages. Proper use of the Harvest software is | |
68 | * entirely the responsibility of the user. | |
69 | * | |
70 | * DERIVATIVE WORKS | |
71 | * | |
72 | * Users may make derivative works from the Harvest software, subject | |
73 | * to the following constraints: | |
74 | * | |
75 | * - You must include the above copyright notice and these | |
76 | * accompanying paragraphs in all forms of derivative works, | |
77 | * and any documentation and other materials related to such | |
78 | * distribution and use acknowledge that the software was | |
79 | * developed at the above institutions. | |
80 | * | |
81 | * - You must notify IRTF-RD regarding your distribution of | |
82 | * the derivative work. | |
83 | * | |
84 | * - You must clearly notify users that your are distributing | |
85 | * a modified version and not the original Harvest software. | |
86 | * | |
87 | * - Any derivative product is also subject to these copyright | |
88 | * and use restrictions. | |
89 | * | |
90 | * Note that the Harvest software is NOT in the public domain. We | |
91 | * retain copyright, as specified above. | |
92 | * | |
93 | * HISTORY OF FREE SOFTWARE STATUS | |
94 | * | |
95 | * Originally we required sites to license the software in cases | |
96 | * where they were going to build commercial products/services | |
97 | * around Harvest. In June 1995 we changed this policy. We now | |
98 | * allow people to use the core Harvest software (the code found in | |
99 | * the Harvest ``src/'' directory) for free. We made this change | |
100 | * in the interest of encouraging the widest possible deployment of | |
101 | * the technology. The Harvest software is really a reference | |
102 | * implementation of a set of protocols and formats, some of which | |
103 | * we intend to standardize. We encourage commercial | |
104 | * re-implementations of code complying to this set of standards. | |
105 | */ | |
ed43818f | 106 | |
44a47c6e | 107 | #include "squid.h" |
090089c4 | 108 | |
090089c4 | 109 | static char *debug_log_file = NULL; |
123abbe1 | 110 | static int Ctx_Lock = 0; |
4873d3a4 | 111 | static const char *debugLogTime(time_t); |
123abbe1 | 112 | static void ctx_print(); |
24382924 | 113 | |
114 | #ifdef __STDC__ | |
b8d8561b | 115 | void |
a3d5953d | 116 | _db_print(const char *format,...) |
090089c4 | 117 | { |
75e5a32e | 118 | #if defined(__QNX__) |
119 | va_list eargs; | |
120 | #endif | |
090089c4 | 121 | va_list args; |
122 | #else | |
b8d8561b | 123 | void |
124 | _db_print(va_alist) | |
090089c4 | 125 | va_dcl |
126 | { | |
090089c4 | 127 | va_list args; |
0ee4272b | 128 | const char *format = NULL; |
97f61b08 | 129 | #endif |
95d659f0 | 130 | LOCAL_ARRAY(char, f, BUFSIZ); |
233794cd | 131 | #if HAVE_SYSLOG |
95d659f0 | 132 | LOCAL_ARRAY(char, tmpbuf, BUFSIZ); |
233794cd | 133 | #endif |
090089c4 | 134 | |
24382924 | 135 | #ifdef __STDC__ |
97f61b08 | 136 | va_start(args, format); |
75e5a32e | 137 | #if defined(__QNX__) |
138 | va_start(eargs, format); | |
139 | #endif | |
090089c4 | 140 | #else |
141 | va_start(args); | |
74946a0f | 142 | format = va_arg(args, const char *); |
143 | #endif | |
144 | ||
145 | if (debug_log == NULL) | |
146 | return; | |
123abbe1 | 147 | /* give a chance to context-based debugging to print current context */ |
148 | if (!Ctx_Lock) | |
149 | ctx_print(); | |
042461c3 | 150 | snprintf(f, BUFSIZ, "%s| %s", |
4873d3a4 | 151 | debugLogTime(squid_curtime), |
396c5745 | 152 | format); |
db40ae20 | 153 | #if HAVE_SYSLOG |
12b9e9b1 | 154 | /* level 0 go to syslog */ |
a3d5953d | 155 | if (_db_level == 0 && opt_syslog_enable) { |
12b9e9b1 | 156 | tmpbuf[0] = '\0'; |
042461c3 | 157 | vsnprintf(tmpbuf, BUFSIZ, format, args); |
233794cd | 158 | tmpbuf[1023] = '\0'; |
159 | syslog(LOG_ERR, "%s", tmpbuf); | |
12b9e9b1 | 160 | } |
db40ae20 | 161 | #endif /* HAVE_SYSLOG */ |
12b9e9b1 | 162 | /* write to log file */ |
75e5a32e | 163 | #if defined(__QNX__) |
164 | vfprintf(debug_log, f, eargs); | |
165 | #else | |
12b9e9b1 | 166 | vfprintf(debug_log, f, args); |
75e5a32e | 167 | #endif |
17a0a4ee | 168 | if (!Config.onoff.buffered_logs) |
12b9e9b1 | 169 | fflush(debug_log); |
4873d3a4 | 170 | if (opt_debug_stderr >= _db_level && debug_log != stderr) { |
75e5a32e | 171 | #if defined(__QNX__) |
067bea91 | 172 | vfprintf(stderr, f, eargs); |
75e5a32e | 173 | #else |
0d90407c | 174 | vfprintf(stderr, f, args); |
75e5a32e | 175 | #endif |
176 | } | |
177 | #if defined(__QNX__) | |
178 | va_end(eargs); | |
179 | #endif | |
090089c4 | 180 | va_end(args); |
181 | } | |
182 | ||
b8d8561b | 183 | static void |
0ee4272b | 184 | debugArg(const char *arg) |
12b9e9b1 | 185 | { |
c9f06944 | 186 | int s = 0; |
187 | int l = 0; | |
188 | int i; | |
12b9e9b1 | 189 | |
c9f06944 | 190 | if (!strncasecmp(arg, "ALL", 3)) { |
191 | s = -1; | |
192 | arg += 4; | |
193 | } else { | |
194 | s = atoi(arg); | |
195 | while (*arg && *arg++ != ','); | |
196 | } | |
197 | l = atoi(arg); | |
198 | ||
199 | if (s >= 0) { | |
200 | debugLevels[s] = l; | |
201 | return; | |
202 | } | |
203 | for (i = 0; i < MAX_DEBUG_SECTIONS; i++) | |
204 | debugLevels[i] = l; | |
12b9e9b1 | 205 | } |
206 | ||
b8d8561b | 207 | static void |
0ee4272b | 208 | debugOpenLog(const char *logfile) |
ccff9601 | 209 | { |
210 | if (logfile == NULL) { | |
211 | debug_log = stderr; | |
212 | return; | |
213 | } | |
214 | if (debug_log_file) | |
5c46528b | 215 | xfree(debug_log_file); |
ccff9601 | 216 | debug_log_file = xstrdup(logfile); /* keep a static copy */ |
f2cc1af5 | 217 | if (debug_log && debug_log != stderr) |
a0bbd6c8 | 218 | fclose(debug_log); |
ccff9601 | 219 | debug_log = fopen(logfile, "a+"); |
220 | if (!debug_log) { | |
221 | fprintf(stderr, "WARNING: Cannot write log file: %s\n", logfile); | |
222 | perror(logfile); | |
223 | fprintf(stderr, " messages will be sent to 'stderr'.\n"); | |
224 | fflush(stderr); | |
225 | debug_log = stderr; | |
226 | } | |
227 | } | |
228 | ||
b8d8561b | 229 | void |
0ee4272b | 230 | _db_init(const char *logfile, const char *options) |
090089c4 | 231 | { |
12b9e9b1 | 232 | int i; |
233 | char *p = NULL; | |
234 | char *s = NULL; | |
090089c4 | 235 | |
12b9e9b1 | 236 | for (i = 0; i < MAX_DEBUG_SECTIONS; i++) |
237 | debugLevels[i] = -1; | |
090089c4 | 238 | |
30a4f2a8 | 239 | if (options) { |
240 | p = xstrdup(options); | |
241 | for (s = strtok(p, w_space); s; s = strtok(NULL, w_space)) | |
12b9e9b1 | 242 | debugArg(s); |
12b9e9b1 | 243 | xfree(p); |
244 | } | |
ccff9601 | 245 | debugOpenLog(logfile); |
090089c4 | 246 | |
30a4f2a8 | 247 | #if HAVE_SYSLOG && defined(LOG_LOCAL4) |
6e40f263 | 248 | if (opt_syslog_enable) |
b8de7ebe | 249 | openlog(appname, LOG_PID | LOG_NDELAY | LOG_CONS, LOG_LOCAL4); |
db40ae20 | 250 | #endif /* HAVE_SYSLOG */ |
251 | ||
090089c4 | 252 | } |
253 | ||
b8d8561b | 254 | void |
0673c0ba | 255 | _db_rotate_log(void) |
090089c4 | 256 | { |
257 | int i; | |
95d659f0 | 258 | LOCAL_ARRAY(char, from, MAXPATHLEN); |
259 | LOCAL_ARRAY(char, to, MAXPATHLEN); | |
88738790 | 260 | #ifdef S_ISREG |
2edc2504 | 261 | struct stat sb; |
88738790 | 262 | #endif |
090089c4 | 263 | |
264 | if (debug_log_file == NULL) | |
265 | return; | |
71d95578 | 266 | #ifdef S_ISREG |
2edc2504 | 267 | if (stat(debug_log_file, &sb) == 0) |
268 | if (S_ISREG(sb.st_mode) == 0) | |
269 | return; | |
71d95578 | 270 | #endif |
090089c4 | 271 | |
272 | /* Rotate numbers 0 through N up one */ | |
b6f794d6 | 273 | for (i = Config.Log.rotateNumber; i > 1;) { |
090089c4 | 274 | i--; |
042461c3 | 275 | snprintf(from, MAXPATHLEN, "%s.%d", debug_log_file, i - 1); |
276 | snprintf(to, MAXPATHLEN, "%s.%d", debug_log_file, i); | |
090089c4 | 277 | rename(from, to); |
278 | } | |
279 | /* Rotate the current log to .0 */ | |
b6f794d6 | 280 | if (Config.Log.rotateNumber > 0) { |
042461c3 | 281 | snprintf(to, MAXPATHLEN, "%s.%d", debug_log_file, 0); |
090089c4 | 282 | rename(debug_log_file, to); |
283 | } | |
284 | /* Close and reopen the log. It may have been renamed "manually" | |
285 | * before HUP'ing us. */ | |
0a8020d1 | 286 | if (debug_log != stderr) |
b6f794d6 | 287 | debugOpenLog(Config.Log.log); |
090089c4 | 288 | } |
4873d3a4 | 289 | |
290 | static const char * | |
291 | debugLogTime(time_t t) | |
292 | { | |
293 | struct tm *tm; | |
294 | static char buf[128]; | |
295 | static time_t last_t = 0; | |
296 | if (t != last_t) { | |
2ac76861 | 297 | tm = localtime(&t); |
298 | strftime(buf, 127, "%Y/%m/%d %H:%M:%S", tm); | |
299 | last_t = t; | |
4873d3a4 | 300 | } |
301 | return buf; | |
302 | } | |
303 | ||
123abbe1 | 304 | /* |
305 | * Context-based Debugging | |
26970499 | 306 | * |
307 | * Rationale | |
308 | * --------- | |
309 | * | |
310 | * When you have a long nested processing sequence, it is often impossible | |
311 | * for low level routines to know in what larger context they operate. If a | |
312 | * routine coredumps, one can restore the context using debugger trace. | |
313 | * However, in many case you do not want to coredump, but just want to report | |
314 | * a potential problem. A report maybe useless out of problem context. | |
315 | * | |
316 | * To solve this potential problem, use the following approach: | |
317 | * | |
318 | * int | |
319 | * top_level_foo(const char *url) | |
320 | * { | |
321 | * // define current context | |
322 | * // note: we stack but do not dup ctx descriptions! | |
323 | * Ctx ctx = ctx_enter(url); | |
324 | * ... | |
325 | * // go down; middle_level_bar will eventually call bottom_level_boo | |
326 | * middle_level_bar(method, protocol); | |
327 | * ... | |
328 | * // exit, clean after yourself | |
329 | * ctx_exit(ctx); | |
330 | * } | |
331 | * | |
332 | * void | |
333 | * bottom_level_boo(int status, void *data) | |
334 | * { | |
335 | * // detect exceptional condition, and simply report it, the context | |
336 | * // information will be available somewhere close in the log file | |
337 | * if (status == STRANGE_STATUS) | |
338 | * debug(13, 6) ("DOS attack detected, data: %p\n", data); | |
339 | * ... | |
340 | * } | |
341 | * | |
342 | * Current implementation is extremely simple but still very handy. It has a | |
343 | * negligible overhead (descriptions are not duplicated). | |
344 | * | |
345 | * When the _first_ debug message for a given context is printed, it is | |
346 | * prepended with the current context description. Context is printed with | |
347 | * the same debugging level as the original message. | |
348 | * | |
349 | * Note that we do not print context every type you do ctx_enter(). This | |
350 | * approach would produce too many useless messages. For the same reason, a | |
351 | * context description is printed at most _once_ even if you have 10 | |
352 | * debugging messages within one context. | |
353 | * | |
354 | * Contexts can be nested, of course. You must use ctx_enter() to enter a | |
355 | * context (push it onto stack). It is probably safe to exit several nested | |
356 | * contexts at _once_ by calling ctx_exit() at the top level (this will pop | |
357 | * all context till current one). However, as in any stack, you cannot start | |
358 | * in the middle. | |
359 | * | |
360 | * Analysis: | |
361 | * i) locate debugging message, | |
362 | * ii) locate current context by going _upstream_ in your log file, | |
363 | * iii) hack away. | |
364 | * | |
365 | * | |
123abbe1 | 366 | * To-Do: |
26970499 | 367 | * ----- |
368 | * | |
123abbe1 | 369 | * decide if we want to dup() descriptions (adds overhead) but allows to |
370 | * add printf()-style interface | |
26970499 | 371 | * |
2ac76861 | 372 | * implementation: |
26970499 | 373 | * --------------- |
2ac76861 | 374 | * |
123abbe1 | 375 | * descriptions for contexts over CTX_MAX_LEVEL limit are ignored, you probably |
376 | * have a bug if your nesting goes that deep. | |
377 | */ | |
2ac76861 | 378 | |
123abbe1 | 379 | #define CTX_MAX_LEVEL 255 |
2ac76861 | 380 | |
381 | /* | |
382 | * produce a warning when nesting reaches this level and then double | |
383 | * the level | |
384 | */ | |
385 | static int Ctx_Warn_Level = 32; | |
123abbe1 | 386 | /* all descriptions has been printed up to this level */ |
a3f9588e | 387 | static int Ctx_Reported_Level = -1; |
123abbe1 | 388 | /* descriptions are still valid or active up to this level */ |
a3f9588e | 389 | static int Ctx_Valid_Level = -1; |
123abbe1 | 390 | /* current level, the number of nested ctx_enter() calls */ |
a3f9588e | 391 | static int Ctx_Current_Level = -1; |
123abbe1 | 392 | /* saved descriptions (stack) */ |
2ac76861 | 393 | static const char *Ctx_Descrs[CTX_MAX_LEVEL + 1]; |
b70d1c58 | 394 | /* "safe" get secription */ |
395 | static const char *ctx_get_descr(Ctx ctx); | |
123abbe1 | 396 | |
397 | ||
398 | Ctx | |
399 | ctx_enter(const char *descr) | |
400 | { | |
401 | Ctx_Current_Level++; | |
402 | ||
403 | if (Ctx_Current_Level <= CTX_MAX_LEVEL) | |
404 | Ctx_Descrs[Ctx_Current_Level] = descr; | |
405 | ||
406 | if (Ctx_Current_Level == Ctx_Warn_Level) { | |
2ac76861 | 407 | debug(0, 0) ("# ctx: suspiciously deep (%d) nesting:\n", Ctx_Warn_Level); |
123abbe1 | 408 | Ctx_Warn_Level *= 2; |
409 | } | |
123abbe1 | 410 | return Ctx_Current_Level; |
411 | } | |
412 | ||
413 | void | |
414 | ctx_exit(Ctx ctx) | |
415 | { | |
416 | assert(ctx >= 0); | |
2ac76861 | 417 | Ctx_Current_Level = (ctx >= 0) ? ctx - 1 : -1; |
123abbe1 | 418 | if (Ctx_Valid_Level > Ctx_Current_Level) |
419 | Ctx_Valid_Level = Ctx_Current_Level; | |
420 | } | |
421 | ||
422 | /* | |
423 | * the idea id to print each context description at most once but provide enough | |
424 | * info for deducing the current execution stack | |
425 | */ | |
426 | static void | |
427 | ctx_print() | |
428 | { | |
429 | /* lock so _db_print will not call us recursively */ | |
430 | Ctx_Lock++; | |
431 | /* ok, user saw [0,Ctx_Reported_Level] descriptions */ | |
432 | /* first inform about entries popped since user saw them */ | |
433 | if (Ctx_Valid_Level < Ctx_Reported_Level) { | |
2ac76861 | 434 | if (Ctx_Reported_Level != Ctx_Valid_Level + 1) |
435 | _db_print("ctx: exit levels from %2d down to %2d\n", | |
436 | Ctx_Reported_Level, Ctx_Valid_Level + 1); | |
4a0d3a91 | 437 | else |
438 | _db_print("ctx: exit level %2d\n", Ctx_Reported_Level); | |
123abbe1 | 439 | Ctx_Reported_Level = Ctx_Valid_Level; |
440 | } | |
441 | /* report new contexts that were pushed since last report */ | |
442 | while (Ctx_Reported_Level < Ctx_Current_Level) { | |
443 | Ctx_Reported_Level++; | |
444 | Ctx_Valid_Level++; | |
2ac76861 | 445 | _db_print("ctx: enter level %2d: '%s'\n", Ctx_Reported_Level, |
b70d1c58 | 446 | ctx_get_descr(Ctx_Reported_Level)); |
123abbe1 | 447 | } |
448 | /* unlock */ | |
449 | Ctx_Lock--; | |
450 | } | |
b70d1c58 | 451 | |
452 | /* checks for nulls and overflows */ | |
453 | static const char * | |
454 | ctx_get_descr(Ctx ctx) | |
455 | { | |
2ac76861 | 456 | if (ctx < 0 || ctx > CTX_MAX_LEVEL) |
457 | return "<lost>"; | |
b70d1c58 | 458 | return Ctx_Descrs[ctx] ? Ctx_Descrs[ctx] : "<null>"; |
459 | } |