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