cdsa/cdsa_utilities/debugging.cpp

   1 /*
   2  * Copyright (c) 2000-2001 Apple Computer, Inc. All Rights Reserved.
   3  *
   4  * The contents of this file constitute Original Code as defined in and are
   5  * subject to the Apple Public Source License Version 1.2 (the 'License').
   6  * You may not use this file except in compliance with the License. Please obtain
   7  * a copy of the License at http://www.apple.com/publicsource and read it before
   8  * using this file.
   9  *
  10  * This Original Code and all software distributed under the License are
  11  * distributed on an 'AS IS' basis, WITHOUT WARRANTY OF ANY KIND, EITHER EXPRESS
  12  * OR IMPLIED, AND APPLE HEREBY DISCLAIMS ALL SUCH WARRANTIES, INCLUDING WITHOUT
  13  * LIMITATION, ANY WARRANTIES OF MERCHANTABILITY, FITNESS FOR A PARTICULAR
  14  * PURPOSE, QUIET ENJOYMENT OR NON-INFRINGEMENT. Please see the License for the
  15  * specific language governing rights and limitations under the License.
  16  */
  17
  18
  19 //
  20 // debugging - non-trivial debugging support
  21 //
  22 #include <Security/debugsupport.h>
  23 #include <Security/globalizer.h>
  24 #include <cstdarg>
  25 #include <ctype.h>
  26
  27 #define SYSLOG_NAMES    // compile syslog name tables
  28 #include <syslog.h>
  29
  30 #include <cxxabi.h>     // for name demangling
  31
  32 // enable kernel tracing
  33 #define ENABLE_SECTRACE 1
  34
  35
  36 namespace Security {
  37 namespace Debug {
  38
  39
  40 //
  41 // Main debug functions (global and in-scope)
  42 //
  43 void debug(const char *scope, const char *format, ...)
  44 {
  45 #if !defined(NDEBUG_CODE)
  46         va_list args;
  47         va_start(args, format);
  48         Target::get().message(scope, format, args);
  49         va_end(args);
  50 #endif
  51 }
  52
  53 void vdebug(const char *scope, const char *format, va_list args)
  54 {
  55 #if !defined(NDEBUG_CODE)
  56     Target::get().message(scope, format, args);
  57 #endif
  58 }
  59
  60 bool debugging(const char *scope)
  61 {
  62 #if !defined(NDEBUG_CODE)
  63         return Target::get().debugging(scope);
  64 #else
  65     return false;
  66 #endif
  67 }
  68
  69
  70 //
  71 // C equivalents for some basic uses
  72 //
  73 extern "C" {
  74         int __security_debugging(const char *scope);
  75         void __security_debug(const char *scope, const char *format, ...);
  76 };
  77
  78 int __security_debugging(const char *scope)
  79 { return debugging(scope); }
  80
  81 void __security_debug(const char *scope, const char *format, ...)
  82 {
  83 #if !defined(NDEBUG_CODE)
  84         va_list args;
  85         va_start(args, format);
  86         vdebug(scope, format, args);
  87         va_end(args);
  88 #endif
  89 }
  90
  91
  92 //
  93 // Dump facility
  94 //
  95 bool dumping(const char *scope)
  96 {
  97 #if defined(NDEBUG_STUBS)
  98     return false;
  99 #else
 100         return Target::get().dump(scope);
 101 #endif
 102 }
 103
 104 void dump(const char *format, ...)
 105 {
 106 #if !defined(NDEBUG_CODE)
 107         va_list args;
 108         va_start(args, format);
 109         Target::get().dump(format, args);
 110         va_end(args);
 111 #endif
 112 }
 113
 114 void dumpData(const void *ptr, size_t size)
 115 {
 116 #if !defined(NDEBUG_CODE)
 117         const char *addr = reinterpret_cast<const char *>(ptr);
 118         const char *end = addr + size;
 119         bool isText = true;
 120         for (const char *p = addr; p < end; p++)
 121                 if (!isprint(*p)) { isText = false; break; }
 122
 123         if (isText) {
 124                 dump("\"");
 125                 for (const char *p = addr; p < end; p++)
 126                         dump("%c", *p);
 127                 dump("\"");
 128         } else {
 129                 dump("0x");
 130                 for (const char *p = addr; p < end; p++)
 131                         dump("%2.2x", static_cast<unsigned char>(*p));
 132         }
 133 #endif //NDEBUG_STUBS
 134 }
 135
 136 void dumpData(const char *title, const void *ptr, size_t size)
 137 {
 138 #if !defined(NDEBUG_CODE)
 139         dump("%s: ", title);
 140         dumpData(ptr, size);
 141         dump("\n");
 142 #endif //NDEBUG_STUBS
 143 }
 144
 145
 146 //
 147 // Turn a C++ typeid into a nice type name.
 148 // This uses the C++ ABI where available.
 149 // We're stripping out a few C++ prefixes; they're pretty redundant (and obvious).
 150 //
 151 string makeTypeName(const type_info &type)
 152 {
 153         int status;
 154         char *cname = abi::__cxa_demangle(type.name(), NULL, NULL, &status);
 155         string name = !strncmp(cname, "Security::", 10) ? (cname + 10) :
 156                 !strncmp(cname, "std::", 5) ? (cname + 5) :
 157                 cname;
 158         ::free(cname);  // yes, really (ABI rules)
 159         return name;
 160 }
 161
 162
 163 //
 164 // Target initialization
 165 //
 166 #if !defined(NDEBUG_CODE)
 167
 168 Target::Target()
 169         : showScope(false), showThread(false), showPid(false),
 170           sink(NULL)
 171 {
 172         // put into singleton slot if first
 173         if (singleton == NULL)
 174                 singleton = this;
 175
 176         // insert terminate handler
 177         if (!previousTerminator)        // first time we do this
 178                 previousTerminator = set_terminate(terminator);
 179 }
 180
 181 Target::~Target()
 182 {
 183 }
 184
 185
 186 //
 187 // The core logging function of a Target
 188 //
 189 void Target::message(const char *scope, const char *format, va_list args)
 190 {
 191         if (logSelector(scope)) {
 192                 // note: messageConstructionSize is big enough for all prefixes constructed
 193                 char buffer[messageConstructionSize];   // building the message here
 194                 char *bufp = buffer;
 195                 if (showScope && scope) {               // add "scope "
 196                         if (const char *sep = strchr(scope, ',')) {
 197                                 bufp += sprintf(bufp, "%-*s", Name::maxLength, (const char *)Name(scope, sep));
 198                         } else {        // single scope
 199                                 bufp += sprintf(bufp, "%-*s", Name::maxLength, scope);
 200                         }
 201                 }
 202                 if (showPid) {          // add "[Pid] "
 203                         bufp += sprintf(bufp, "[%d] ", getpid());
 204                 }
 205                 if (showThread) {               // add "#Tthreadid "
 206                         *bufp++ = '#';
 207                         Thread::Identity::current().getIdString(bufp);
 208                         bufp += strlen(bufp);
 209                         *bufp++ = ' ';
 210                 }
 211                 vsnprintf(bufp, buffer + sizeof(buffer) - bufp, format, args);
 212         for (char *p = bufp; *p; p++)
 213             if (!isprint(*p))
 214                 *p = '?';
 215                 sink->put(buffer, bufp - buffer);
 216         }
 217 }
 218
 219 bool Target::debugging(const char *scope)
 220 {
 221         return logSelector(scope);
 222 }
 223
 224
 225 //
 226 // The core debug-dump function of a target
 227 //
 228 void Target::dump(const char *format, va_list args)
 229 {
 230         char buffer[messageConstructionSize];   // building the message here
 231         vsnprintf(buffer, sizeof(buffer), format, args);
 232         for (char *p = buffer; *p; p++)
 233                 if (!isprint(*p) && !isspace(*p) || *p == '\r')
 234                         *p = '?';
 235         sink->dump(buffer);
 236 }
 237
 238 bool Target::dump(const char *scope)
 239 {
 240         return dumpSelector(scope);
 241 }
 242
 243
 244 //
 245 // Selector objects.
 246 //
 247 Target::Selector::Selector() : useSet(false), negate(false)
 248 { }
 249
 250 void Target::Selector::operator = (const char *scope)
 251 {
 252         if (scope) {
 253                 // initial values
 254                 if (!strcmp(scope, "all")) {
 255                         useSet = false;
 256                         negate = true;
 257                 } else if (!strcmp(scope, "none")) {
 258                         useSet = negate = false;
 259                 } else {
 260                         useSet = true;
 261                         enableSet.erase(enableSet.begin(), enableSet.end());
 262                         if (scope[0] == '-') {
 263                                 negate = true;
 264                                 scope++;
 265                         } else
 266                                 negate = false;
 267                         while (const char *sep = strchr(scope, ',')) {
 268                                 enableSet.insert(Name(scope, sep));
 269                                 scope = sep + 1;
 270                         }
 271                         enableSet.insert(scope);
 272                 }
 273         } else {
 274                 useSet = negate = false;
 275         }
 276 }
 277
 278 bool Target::Selector::operator () (const char *scope) const
 279 {
 280         // a scope of NULL is a special override; it always qualifies
 281         if (scope == NULL)
 282                 return true;
 283
 284         if (useSet) {
 285                 while (const char *sep = strchr(scope, ',')) {
 286                         if (enableSet.find(Name(scope, sep)) != enableSet.end())
 287                                 return !negate;
 288                         scope = sep + 1;
 289                 }
 290                 return (enableSet.find(scope) != enableSet.end()) != negate;
 291         } else {
 292                 return negate;
 293         }
 294 }
 295
 296
 297 //
 298 // Establish Target state from the environment
 299 //
 300 void Target::setFromEnvironment()
 301 {
 302         // set scopes
 303         logSelector = getenv("DEBUGSCOPE");
 304         dumpSelector = getenv("DEBUGDUMP");
 305
 306         //
 307         // Set and configure destination. Currently available:
 308         //      /some/where -> that file
 309         //      LOG_SOMETHING -> syslog facility
 310         //      >&number -> that (already) open file descriptor
 311         //      anything else -> try as a filename sight unseen
 312         //      DEBUGDEST not set -> stderr
 313         //      anything in error -> stderr (with an error message on it)
 314         //
 315         if (const char *dest = getenv("DEBUGDEST")) {
 316                 if (dest[0] == '/') {   // full pathname, write to file
 317                         to(dest);
 318                 } else if (!strncmp(dest, "LOG_", 4)) { // syslog
 319                         int facility = LOG_DAEMON;
 320                         for (CODE *cp = facilitynames; cp->c_name; cp++)
 321                                 if (!strcmp(dest, cp->c_name))
 322                                         facility = cp->c_val;
 323                         to(facility | LOG_DEBUG);
 324                 } else if (!strncmp(dest, ">&", 2)) {   // to file descriptor
 325                         int fd = atoi(dest+2);
 326                         if (FILE *f = fdopen(fd, "a")) {
 327                                 to(f);
 328                         } else {
 329                                 to(stderr);
 330                                 ::debug(NULL, "cannot log to fd[%d]: %s", fd, strerror(errno));
 331                         }
 332                 } else {        // if everything else fails, write a file
 333                         to(dest);
 334                 }
 335         } else {                // default destination is stderr
 336                 to(stderr);
 337         }
 338         configure();
 339 }
 340
 341
 342 void Target::configure()
 343 {
 344         configure(getenv("DEBUGOPTIONS"));
 345 }
 346
 347 void Target::configure(const char *config)
 348 {
 349         // configure global options
 350         showScope = config && strstr(config, "scope");
 351         showThread = config && strstr(config, "thread");
 352         showPid = config && strstr(config, "pid");
 353
 354         // configure sink
 355         if (sink)
 356                 sink->configure(config);
 357 }
 358
 359
 360 //
 361 // Explicit destination assignments
 362 //
 363 void Target::to(Sink *s)
 364 {
 365         delete sink;
 366         sink = s;
 367 }
 368
 369 void Target::to(FILE *file)
 370 {
 371         to(new FileSink(file));
 372 }
 373
 374 void Target::to(const char *filename)
 375 {
 376         if (FILE *f = fopen(filename, "a")) {
 377                 to(new FileSink(f));
 378         } else {
 379                 to(stderr);
 380                 ::debug(NULL, "cannot debug to \"%s\": %s", filename, strerror(errno));
 381         }
 382 }
 383
 384 void Target::to(int syslogPriority)
 385 {
 386         to(new SyslogSink(syslogPriority));
 387 }
 388
 389
 390 //
 391 // Making and retrieving the default singleton
 392 //
 393 Target *Target::singleton;
 394
 395 Target &Target::get()
 396 {
 397         if (singleton == NULL) {
 398                 Target *t = new Target;
 399                 t->setFromEnvironment();
 400         }
 401         return *singleton;
 402 }
 403
 404
 405 //
 406 // Standard sink implementations
 407 //
 408 Target::Sink::~Sink()
 409 { }
 410
 411 void Target::Sink::dump(const char *)
 412 { }
 413
 414 void Target::Sink::configure(const char *)
 415 { }
 416
 417
 418 //
 419 // The terminate handler installed when a Target is created
 420 //
 421 terminate_handler Target::previousTerminator;
 422
 423 void Target::terminator()
 424 {
 425         debug("exception", "uncaught exception terminates program");
 426         previousTerminator();
 427         debug("exception", "prior termination handler failed to abort; forcing abort");
 428         abort();
 429 }
 430
 431
 432 //
 433 // File sinks (write to file via stdio)
 434 //
 435 void FileSink::put(const char *buffer, unsigned int)
 436 {
 437         StLock<Mutex> locker(lock, false);
 438         if (lockIO)
 439                 locker.lock();
 440         if (addDate) {
 441                 time_t now = time(NULL);
 442                 char *date = ctime(&now);
 443                 date[19] = '\0';
 444                 fprintf(file, "%s ", date + 4); // Nov 24 18:22:48
 445         }
 446         fputs(buffer, file);
 447         putc('\n', file);
 448 }
 449
 450 void FileSink::dump(const char *text)
 451 {
 452         StLock<Mutex> locker(lock, false);
 453         if (lockIO)
 454                 locker.lock();
 455         fputs(text, file);
 456 }
 457
 458 void FileSink::configure(const char *options)
 459 {
 460         if (options == NULL || !strstr(options, "noflush")) {
 461                 // we mean "if the file isn't unbuffered", but what's the portable way to say that?
 462                 if (file != stderr)
 463                 setlinebuf(file);
 464         }
 465         if (options) {
 466                 addDate = strstr(options, "date");
 467                 lockIO = !strstr(options, "nolock");
 468         }
 469 }
 470
 471
 472 //
 473 // Syslog sinks (write to syslog)
 474 //
 475 void SyslogSink::put(const char *buffer, unsigned int)
 476 {
 477         syslog(priority, "%s", buffer);
 478 }
 479
 480 void SyslogSink::dump(const char *text)
 481 {
 482         // add to dump buffer
 483         snprintf(dumpPtr, dumpBuffer + dumpBufferSize - dumpPtr, "%s", text);
 484
 485         // take off full lines and submit
 486         char *p = dumpBase;
 487         while (char *q = strchr(p, '\n')) {
 488                 *q++ = '\0';    // terminate/break
 489                 syslog(priority, " @@ %s", p);
 490                 p = q;
 491         }
 492
 493         if (*p) {       // left-over unterminated line segment in buffer
 494                 dumpPtr = p + strlen(p);
 495                 if ((dumpBase = p) > dumpBuffer + dumpBufferSize / 2) {
 496                         // shift buffer down to make room
 497                         memmove(dumpBuffer, dumpBase, dumpPtr - dumpBase);
 498                         dumpPtr -= (dumpBase - dumpBuffer);
 499                         dumpBase = dumpBuffer;
 500                 }
 501         } else {        // buffer is empty; reset to start
 502                 dumpBase = dumpPtr = dumpBuffer;
 503         }
 504 }
 505
 506 void SyslogSink::configure(const char *options)
 507 {
 508 }
 509
 510 #endif //NDEBUG_CODE
 511
 512
 513 //
 514 // kernel tracing support (C version)
 515 //
 516 extern "C" void security_ktrace(int);
 517
 518 void security_ktrace(int code)
 519 {
 520 #if defined(ENABLE_SECTRACE)
 521         syscall(180, code, 0, 0, 0, 0);
 522 #endif
 523 }
 524
 525
 526 } // end namespace Debug
 527 } // end namespace Security