4
* DEBUG: section 00 Debug Routines
5
* AUTHOR: Harvest Derived
7
* SQUID Web Proxy Cache http://www.squid-cache.org/
8
* ----------------------------------------------------------
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.
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.
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.
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
31
* Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111, USA.
36
#include "SquidTime.h"
39
/* for shutting_down flag in xassert() */
42
/* cope with no squid.h */
44
#define MAXPATHLEN 256
47
char *Debug::debugOptions = NULL;
48
int Debug::override_X = 0;
49
int Debug::log_stderr = -1;
50
bool Debug::log_syslog = false;
51
int Debug::Levels[MAX_DEBUG_SECTIONS];
53
char *Debug::cache_log = NULL;
54
int Debug::rotateNumber = -1;
55
FILE *debug_log = NULL;
56
static char *debug_log_file = NULL;
57
static int Ctx_Lock = 0;
58
static const char *debugLogTime(void);
59
static void ctx_print(void);
62
static int syslog_facility = 0;
64
static void _db_print_syslog(const char *format, va_list args);
66
static void _db_print_stderr(const char *format, va_list args);
67
static void _db_print_file(const char *format, va_list args);
70
SQUIDCEXTERN LPCRITICAL_SECTION dbg_mutex;
71
typedef BOOL (WINAPI * PFInitializeCriticalSectionAndSpinCount) (LPCRITICAL_SECTION, DWORD);
75
_db_print(const char *format,...)
84
/* Multiple WIN32 threads may call this simultaneously */
87
HMODULE krnl_lib = GetModuleHandle("Kernel32");
88
PFInitializeCriticalSectionAndSpinCount InitializeCriticalSectionAndSpinCount = NULL;
91
InitializeCriticalSectionAndSpinCount =
92
(PFInitializeCriticalSectionAndSpinCount) GetProcAddress(krnl_lib,
93
"InitializeCriticalSectionAndSpinCount");
95
dbg_mutex = static_cast<CRITICAL_SECTION*>(xcalloc(1, sizeof(CRITICAL_SECTION)));
97
if (InitializeCriticalSectionAndSpinCount) {
98
/* let multiprocessor systems EnterCriticalSection() fast */
100
if (!InitializeCriticalSectionAndSpinCount(dbg_mutex, 4000)) {
102
fprintf(debug_log, "FATAL: _db_print: can't initialize critical section\n");
106
fprintf(stderr, "FATAL: _db_print: can't initialize critical section\n");
109
InitializeCriticalSection(dbg_mutex);
113
EnterCriticalSection(dbg_mutex);
116
/* give a chance to context-based debugging to print current context */
120
va_start(args1, format);
121
va_start(args2, format);
122
va_start(args3, format);
124
snprintf(f, BUFSIZ, "%s| %s",
128
_db_print_file(f, args1);
129
_db_print_stderr(f, args2);
132
_db_print_syslog(format, args3);
136
LeaveCriticalSection(dbg_mutex);
145
_db_print_file(const char *format, va_list args)
147
if (debug_log == NULL)
150
/* give a chance to context-based debugging to print current context */
154
vfprintf(debug_log, format, args);
159
_db_print_stderr(const char *format, va_list args)
161
if (Debug::log_stderr < Debug::level)
164
if (debug_log == stderr)
167
vfprintf(stderr, format, args);
172
_db_print_syslog(const char *format, va_list args)
174
/* level 0,1 go to syslog */
176
if (Debug::level > 1)
179
if (!Debug::log_syslog)
185
vsnprintf(tmpbuf, BUFSIZ, format, args);
187
tmpbuf[BUFSIZ - 1] = '\0';
189
syslog(Debug::level == 0 ? LOG_WARNING : LOG_NOTICE, "%s", tmpbuf);
191
#endif /* HAVE_SYSLOG */
194
debugArg(const char *arg)
200
if (!strncasecmp(arg, "rotate=", 7)) {
202
Debug::rotateNumber = atoi(arg);
204
} else if (!strncasecmp(arg, "ALL", 3)) {
209
while (*arg && *arg++ != ',');
215
if (s >= MAX_DEBUG_SECTIONS)
216
s = MAX_DEBUG_SECTIONS-1;
225
Debug::Levels[s] = l;
229
for (i = 0; i < MAX_DEBUG_SECTIONS; i++)
230
Debug::Levels[i] = l;
234
debugOpenLog(const char *logfile)
236
if (logfile == NULL) {
242
xfree(debug_log_file);
244
debug_log_file = xstrdup(logfile); /* keep a static copy */
246
if (debug_log && debug_log != stderr)
249
debug_log = fopen(logfile, "a+");
252
fprintf(stderr, "WARNING: Cannot write log file: %s\n", logfile);
254
fprintf(stderr, " messages will be sent to 'stderr'.\n");
260
setmode(fileno(debug_log), O_TEXT);
268
static struct syslog_facility_name {
273
syslog_facility_names[] = {
282
"authpriv", LOG_AUTHPRIV
383
_db_set_syslog(const char *facility)
385
Debug::log_syslog = true;
390
syslog_facility = LOG_DAEMON;
393
syslog_facility = LOG_LOCAL4;
394
#endif /* LOG_DAEMON */
398
struct syslog_facility_name *n;
400
for (n = syslog_facility_names; n->name; n++) {
401
if (strcmp(n->name, facility) == 0) {
402
syslog_facility = n->facility;
407
fprintf(stderr, "unknown syslog facility '%s'\n", facility);
413
fprintf(stderr, "syslog facility type not supported on your system\n");
415
#endif /* LOG_LOCAL4 */
421
Debug::parseOptions(char const *options)
428
debugs(0, 9, "command-line -X overrides: " << options);
432
for (i = 0; i < MAX_DEBUG_SECTIONS; i++)
433
Debug::Levels[i] = 0;
436
p = xstrdup(options);
438
for (s = strtok(p, w_space); s; s = strtok(NULL, w_space))
446
_db_init(const char *logfile, const char *options)
448
Debug::parseOptions(options);
450
debugOpenLog(logfile);
452
#if HAVE_SYSLOG && defined(LOG_LOCAL4)
454
if (Debug::log_syslog)
455
openlog(APP_SHORTNAME, LOG_PID | LOG_NDELAY | LOG_CONS, syslog_facility);
457
#endif /* HAVE_SYSLOG */
459
/* Pre-Init TZ env, see bug #2656 */
466
if (debug_log_file == NULL)
471
if (stat(debug_log_file, &sb) == 0)
472
if (S_ISREG(sb.st_mode) == 0)
476
char from[MAXPATHLEN];
483
* NOTE: we cannot use xrename here without having it in a
484
* separate file -- tools.c has too many dependencies to be
485
* used everywhere debug.c is used.
487
/* Rotate numbers 0 through N up one */
488
for (int i = Debug::rotateNumber; i > 1;) {
490
snprintf(from, MAXPATHLEN, "%s.%d", debug_log_file, i - 1);
491
snprintf(to, MAXPATHLEN, "%s.%d", debug_log_file, i);
500
* You can't rename open files on Microsoft "operating systems"
501
* so we close before renaming.
504
if (debug_log != stderr)
507
/* Rotate the current log to .0 */
508
if (Debug::rotateNumber > 0) {
509
snprintf(to, MAXPATHLEN, "%s.%d", debug_log_file, 0);
514
rename(debug_log_file, to);
517
/* Close and reopen the log. It may have been renamed "manually"
518
* before HUP'ing us. */
519
if (debug_log != stderr)
520
debugOpenLog(Debug::cache_log);
527
time_t t = getCurrentTime();
530
static char buf[128];
531
static time_t last_t = 0;
533
if (Debug::level > 1) {
536
strftime(buf2, 127, "%Y/%m/%d %H:%M:%S", tm);
538
snprintf(buf, 127, "%s.%03d", buf2, (int) current_time.tv_usec / 1000);
540
} else if (t != last_t) {
542
strftime(buf, 127, "%Y/%m/%d %H:%M:%S", tm);
551
xassert(const char *msg, const char *file, int line)
553
debugs(0, 0, "assertion failed: " << file << ":" << line << ": \"" << msg << "\"");
560
* Context-based Debugging
565
* When you have a long nested processing sequence, it is often impossible
566
* for low level routines to know in what larger context they operate. If a
567
* routine coredumps, one can restore the context using debugger trace.
568
* However, in many case you do not want to coredump, but just want to report
569
* a potential problem. A report maybe useless out of problem context.
571
* To solve this potential problem, use the following approach:
574
* top_level_foo(const char *url)
576
* // define current context
577
* // note: we stack but do not dup ctx descriptions!
578
* Ctx ctx = ctx_enter(url);
580
* // go down; middle_level_bar will eventually call bottom_level_boo
581
* middle_level_bar(method, protocol);
583
* // exit, clean after yourself
588
* bottom_level_boo(int status, void *data)
590
* // detect exceptional condition, and simply report it, the context
591
* // information will be available somewhere close in the log file
592
* if (status == STRANGE_STATUS)
593
* debugs(13, 6, "DOS attack detected, data: " << data);
597
* Current implementation is extremely simple but still very handy. It has a
598
* negligible overhead (descriptions are not duplicated).
600
* When the _first_ debug message for a given context is printed, it is
601
* prepended with the current context description. Context is printed with
602
* the same debugging level as the original message.
604
* Note that we do not print context every type you do ctx_enter(). This
605
* approach would produce too many useless messages. For the same reason, a
606
* context description is printed at most _once_ even if you have 10
607
* debugging messages within one context.
609
* Contexts can be nested, of course. You must use ctx_enter() to enter a
610
* context (push it onto stack). It is probably safe to exit several nested
611
* contexts at _once_ by calling ctx_exit() at the top level (this will pop
612
* all context till current one). However, as in any stack, you cannot start
616
* i) locate debugging message,
617
* ii) locate current context by going _upstream_ in your log file,
624
* decide if we want to dup() descriptions (adds overhead) but allows to
625
* add printf()-style interface
630
* descriptions for contexts over CTX_MAX_LEVEL limit are ignored, you probably
631
* have a bug if your nesting goes that deep.
634
#define CTX_MAX_LEVEL 255
637
* produce a warning when nesting reaches this level and then double
640
static int Ctx_Warn_Level = 32;
641
/* all descriptions has been printed up to this level */
642
static int Ctx_Reported_Level = -1;
643
/* descriptions are still valid or active up to this level */
644
static int Ctx_Valid_Level = -1;
645
/* current level, the number of nested ctx_enter() calls */
646
static int Ctx_Current_Level = -1;
647
/* saved descriptions (stack) */
648
static const char *Ctx_Descrs[CTX_MAX_LEVEL + 1];
649
/* "safe" get secription */
650
static const char *ctx_get_descr(Ctx ctx);
654
ctx_enter(const char *descr)
658
if (Ctx_Current_Level <= CTX_MAX_LEVEL)
659
Ctx_Descrs[Ctx_Current_Level] = descr;
661
if (Ctx_Current_Level == Ctx_Warn_Level) {
662
debugs(0, 0, "# ctx: suspiciously deep (" << Ctx_Warn_Level << ") nesting:");
666
return Ctx_Current_Level;
673
Ctx_Current_Level = (ctx >= 0) ? ctx - 1 : -1;
675
if (Ctx_Valid_Level > Ctx_Current_Level)
676
Ctx_Valid_Level = Ctx_Current_Level;
680
* the idea id to print each context description at most once but provide enough
681
* info for deducing the current execution stack
686
/* lock so _db_print will not call us recursively */
688
/* ok, user saw [0,Ctx_Reported_Level] descriptions */
689
/* first inform about entries popped since user saw them */
691
if (Ctx_Valid_Level < Ctx_Reported_Level) {
692
if (Ctx_Reported_Level != Ctx_Valid_Level + 1)
693
_db_print("ctx: exit levels from %2d down to %2d\n",
694
Ctx_Reported_Level, Ctx_Valid_Level + 1);
696
_db_print("ctx: exit level %2d\n", Ctx_Reported_Level);
698
Ctx_Reported_Level = Ctx_Valid_Level;
701
/* report new contexts that were pushed since last report */
702
while (Ctx_Reported_Level < Ctx_Current_Level) {
703
Ctx_Reported_Level++;
705
_db_print("ctx: enter level %2d: '%s'\n", Ctx_Reported_Level,
706
ctx_get_descr(Ctx_Reported_Level));
713
/* checks for nulls and overflows */
715
ctx_get_descr(Ctx ctx)
717
if (ctx < 0 || ctx > CTX_MAX_LEVEL)
720
return Ctx_Descrs[ctx] ? Ctx_Descrs[ctx] : "<null>";
723
int Debug::TheDepth = 0;
728
assert(TheDepth >= 0);
731
assert(CurrentDebug);
732
*CurrentDebug << std::endl << "reentrant debuging " << TheDepth << "-{";
734
assert(!CurrentDebug);
735
CurrentDebug = new std::ostringstream();
736
// set default formatting flags
737
CurrentDebug->setf(std::ios::fixed);
738
CurrentDebug->precision(2);
740
return *CurrentDebug;
746
assert(TheDepth >= 0);
747
assert(CurrentDebug);
749
*CurrentDebug << "}-" << TheDepth << std::endl;
751
assert(TheDepth == 1);
752
_db_print("%s\n", CurrentDebug->str().c_str());
759
// Hack: replaces global ::xassert() to debug debugging assertions
760
// Relies on assert macro calling xassert() without a specific scope.
762
Debug::xassert(const char *msg, const char *file, int line)
766
*CurrentDebug << "assertion failed: " << file << ":" << line <<
767
": \"" << msg << "\"";
772
std::ostringstream (*Debug::CurrentDebug)(NULL);
added
removed
src/debug.cc
