hphp/util/trace.h

   1 /*
   2    +----------------------------------------------------------------------+
   3    | HipHop for PHP                                                       |
   4    +----------------------------------------------------------------------+
   5    | Copyright (c) 2010-2014 Facebook, Inc. (http://www.facebook.com)     |
   6    +----------------------------------------------------------------------+
   7    | This source file is subject to version 3.01 of the PHP license,      |
   8    | that is bundled with this package in the file LICENSE, and is        |
   9    | available through the world-wide-web at the following url:           |
  10    | http://www.php.net/license/3_01.txt                                  |
  11    | If you did not receive a copy of the PHP license and are unable to   |
  12    | obtain it through the world-wide-web, please send a note to          |
  13    | license@php.net so we can mail you a copy immediately.               |
  14    +----------------------------------------------------------------------+
  15 */
  16
  17 #ifndef incl_HPHP_TRACE_H_
  18 #define incl_HPHP_TRACE_H_
  19
  20 #include <string>
  21 #include <vector>
  22 #include <stdarg.h>
  23
  24 #include "folly/Format.h"
  25
  26 #include "hphp/util/assertions.h"
  27 #include "hphp/util/portability.h"
  28 #include "hphp/util/text-color.h"
  29
  30 /*
  31  * Runtime-selectable trace facility. A trace statement has both a module and a
  32  * level associated with it;  Enable tracing a module by setting the TRACE
  33  * environment variable to a comma-separated list of module:level pairs. E.g.:
  34  *
  35  * env TRACE=tx64:1,bcinterp:3,tmp0:1 ./hhvm/hhvm ...
  36  *
  37  * In a source file, select the compilation unit's module by calling the
  38  * TRACE_SET_MODE macro. E.g.,
  39  *
  40  *   TRACE_SET_MOD(tx64);
  41  *
  42  *   ...
  43  *   TRACE(0, "See this for any trace-enabled build: %d\n", foo);
  44  *   TRACE(1, "Trace-level must be 1 or higher for this one\n");
  45  *
  46  * While the levels are arbitrary integers, code so far is following a
  47  * rough convention of 1-5, where 1 is minimal and 5 is quite verbose.
  48  *
  49  * Normally trace information is printed to /tmp/hphp.log. You can
  50  * override the environment variable HPHP_TRACE_FILE to change
  51  * this. (Note you can set it to something like /dev/stderr or
  52  * /dev/stdout if you want the logs printed to your terminal).
  53  *
  54  * When printing to the terminal, some traces will know how to use
  55  * colorization.  You can set HPHP_TRACE_TTY to tell the tracing
  56  * facility to assume it should colorize even if the output file isn't
  57  * obviously a tty.
  58  */
  59
  60 /*
  61  * Trace levels can be bumped on a per-module, per-scope basis.  This
  62  * lets you run code that has a set of trace levels in a mode as if
  63  * they were all higher.
  64  *
  65  * Example:
  66  *
  67  *   {
  68  *     Trace::Bump bumper{Trace::tx64, 2};
  69  *     FTRACE(1, "asd\n");  // only fires at level >= 3
  70  *   }
  71  *   FTRACE(1, "asd\n");    // back to normal
  72  *
  73  *
  74  * There is also support for conditionally bumping in the bumper:
  75  *
  76  *   {
  77  *     Trace::Bump bumper{Trace::tx64, 2, somePredicate(foo)};
  78  *     // Only bumped if somePredicate(foo) returned true.
  79  *   }
  80  *
  81  * Note however that if you use that form, `somePredicate' will be
  82  * evaluated even if tracing is off.
  83  */
  84
  85 namespace HPHP {
  86 namespace Trace {
  87
  88 #define TRACE_MODULES \
  89       TM(tprefix)     /* Meta: prefix with string */          \
  90       TM(traceAsync)  /* Meta: lazy writes to disk */ \
  91       TM(trans)       \
  92       TM(tx64)        \
  93       TM(tx64stats)   \
  94       TM(ringbuffer)  \
  95       TM(ustubs)      \
  96       TM(unwind)      \
  97       TM(txlease)     \
  98       TM(fixup)       \
  99       TM(tcspace)     \
 100       TM(targetcache) \
 101       TM(treadmill)   \
 102       TM(regalloc)    \
 103       TM(bcinterp)    \
 104       TM(interpOne)   \
 105       TM(dispatchBB)  \
 106       TM(dispatchN)   \
 107       TM(refcount)    \
 108       TM(asmx64)      \
 109       TM(runtime)     \
 110       TM(debugger)    \
 111       TM(debuggerflow) \
 112       TM(debuginfo)   \
 113       TM(stats)       \
 114       TM(emitter)     \
 115       TM(hhbbc)       \
 116       TM(hhbbc_index) \
 117       TM(hhbbc_time)  \
 118       TM(hhbbc_emit)  \
 119       TM(hhbbc_dump)  \
 120       TM(hhbbc_dce)   \
 121       TM(hhbc)        \
 122       TM(stat)        \
 123       TM(fr)          \
 124       TM(intercept)   \
 125       TM(txdeps)      \
 126       TM(typeProfile) \
 127       TM(hhir)        \
 128       TM(printir)     \
 129       TM(pgo)         \
 130       TM(hhirTracelets) \
 131       TM(gc)          \
 132       TM(instancebits)\
 133       TM(hhas)        \
 134       TM(statgroups)  \
 135       TM(minstr)      \
 136       TM(region)      \
 137       TM(atomicvector)\
 138       TM(datablock)   \
 139       TM(jittime)     \
 140       /* Stress categories, to exercise rare paths */ \
 141       TM(stress_txInterpPct)    \
 142       TM(stress_txInterpSeed)   \
 143       /* Jit bisection interval */ \
 144       TM(txOpBisectLow) \
 145       TM(txOpBisectHigh) \
 146       /* smart alloc */ \
 147       TM(smartalloc) \
 148       /* Heap tracing */ \
 149       TM(heap) \
 150       TM(servicereq) \
 151       /* Temporary catetories, to save compilation time */ \
 152       TM(tmp0)  TM(tmp1)  TM(tmp2)  TM(tmp3)               \
 153       TM(tmp4)  TM(tmp5)  TM(tmp6)  TM(tmp7)               \
 154       TM(tmp8)  TM(tmp9)  TM(tmp10) TM(tmp11)              \
 155       TM(tmp12) TM(tmp13) TM(tmp14) TM(tmp15)
 156
 157 enum Module {
 158 #define TM(x) \
 159   x,
 160   TRACE_MODULES
 161 #undef TM
 162   NumModules
 163 };
 164
 165 //////////////////////////////////////////////////////////////////////
 166
 167 /*
 168  * S-expression style structured pretty-printing. Implement
 169  * std::string pretty() const { }, with the convention that
 170  * nested structures are notated as lisp-style trees:
 171  *
 172  *    (<typename> field0 field1)
 173  *
 174  * E.g.:
 175  *    (Location Stack 1)
 176  *    (RuntimeType (Location Stack 1) (Home (Location Local 1)))
 177  *
 178  * The repetitve prettyNode() templates are intended to aid
 179  * implementing pretty().
 180  */
 181
 182 template<typename P1>
 183 std::string prettyNode(const char* name, const std::vector<P1>& vec) {
 184   using std::string;
 185   std::string retval = string("(") + string(name) + string(" ");
 186   for(size_t i = 0; i < vec.size(); i++) {
 187     retval += vec[i].pretty();
 188     if (i != vec.size() - 1) {
 189       retval += string(" ");
 190     }
 191   }
 192   return retval + string(")");
 193 }
 194
 195 template<typename P1>
 196 std::string prettyNode(const char* name, const P1& p1) {
 197   using std::string;
 198   return string("(") + string(name) + string(" ") +
 199     p1.pretty() +
 200     string(")");
 201 }
 202
 203 template<> std::string prettyNode(const char* name, const std::string& s);
 204
 205 template<typename P1, typename P2>
 206 std::string prettyNode(const char* name, const P1& p1, const P2& p2) {
 207   using std::string;
 208   return string("(") + string(name) + string(" ") +
 209     p1.pretty() + string(" ") + p2.pretty() +
 210     string(")");
 211 }
 212
 213 void traceRelease(const char*, ...) ATTRIBUTE_PRINTF(1,2);
 214 void traceRelease(const std::string& s);
 215
 216 template<typename... Args>
 217 void ftraceRelease(Args&&... args) {
 218   traceRelease("%s", folly::format(std::forward<Args>(args)...).str().c_str());
 219 }
 220
 221 // Trace to the global ring buffer in all builds, and also trace normally
 222 // via the standard TRACE(n, ...) macro.
 223 #define TRACE_RB(n, ...)                            \
 224   HPHP::Trace::traceRingBufferRelease(__VA_ARGS__); \
 225   TRACE(n, __VA_ARGS__);
 226 void traceRingBufferRelease(const char* fmt, ...) ATTRIBUTE_PRINTF(1,2);
 227
 228 extern int levels[NumModules];
 229 extern __thread int tl_levels[NumModules];
 230 const char* moduleName(Module mod);
 231 inline bool moduleEnabledRelease(Module tm, int level = 1) {
 232   return levels[tm] + tl_levels[tm] >= level;
 233 }
 234
 235 // Trace::Bump that is on for release tracing.
 236 struct BumpRelease {
 237   BumpRelease(Module mod, int adjust, bool condition = true)
 238     : m_live(condition)
 239     , m_mod(mod)
 240     , m_adjust(adjust)
 241   {
 242     if (m_live) tl_levels[m_mod] -= m_adjust;
 243   }
 244
 245   BumpRelease(BumpRelease&& o)
 246     : m_live(o.m_live)
 247     , m_mod(o.m_mod)
 248     , m_adjust(o.m_adjust)
 249   {
 250     o.m_live = false;
 251   }
 252
 253   ~BumpRelease() {
 254     if (m_live) tl_levels[m_mod] += m_adjust;
 255   }
 256
 257   BumpRelease(const BumpRelease&) = delete;
 258   BumpRelease& operator=(const BumpRelease&) = delete;
 259
 260 private:
 261   bool m_live;
 262   Module m_mod;
 263   int m_adjust;
 264 };
 265
 266 //////////////////////////////////////////////////////////////////////
 267
 268 #if (defined(DEBUG) || defined(USE_TRACE)) /* { */
 269 #  ifndef USE_TRACE
 270 #    define USE_TRACE 1
 271 #  endif
 272
 273 //////////////////////////////////////////////////////////////////////
 274 /*
 275  * Implementation of for when tracing is enabled.
 276  */
 277
 278 inline bool moduleEnabled(Module tm, int level = 1) {
 279   return moduleEnabledRelease(tm, level);
 280 }
 281
 282 inline int moduleLevel(Module tm) { return levels[tm]; }
 283
 284 #define HPHP_TRACE
 285
 286 const bool enabled = true;
 287
 288 #define ONTRACE_MOD(module, n, x) do {    \
 289   if (HPHP::Trace::moduleEnabled(module, n)) {  \
 290     x;                                          \
 291   } } while(0)
 292
 293 #define ONTRACE(n, x) ONTRACE_MOD(TRACEMOD, n, x)
 294
 295 #define TRACE(n, ...) ONTRACE(n, HPHP::Trace::trace(__VA_ARGS__))
 296 #define FTRACE(n, ...)                                        \
 297   ONTRACE(n, HPHP::Trace::trace("%s",                         \
 298              folly::format(__VA_ARGS__).str().c_str()))
 299 #define TRACE_MOD(mod, level, ...) \
 300   ONTRACE_MOD(mod, level, HPHP::Trace::trace(__VA_ARGS__))
 301 #define FTRACE_MOD(mod, level, ...)                     \
 302   ONTRACE_MOD(mod, level, HPHP::Trace::trace("%s",      \
 303              folly::format(__VA_ARGS__).str().c_str()))
 304 #define TRACE_SET_MOD(name)  \
 305   static const HPHP::Trace::Module TRACEMOD = HPHP::Trace::name;
 306
 307 /*
 308  * The Indent struct and ITRACE are used for tracing with nested
 309  * indentation. Create an Indent object on the stack to increase the nesting
 310  * level, then use ITRACE just as you would use FTRACE.
 311  */
 312 extern __thread int indentDepth;
 313 struct Indent {
 314   explicit Indent(int n = 2) : n(n) { indentDepth += n; }
 315   ~Indent()                         { indentDepth -= n; }
 316
 317   int n;
 318 };
 319
 320 // See doc comment above for usage.
 321 using Bump = BumpRelease;
 322
 323 inline std::string indent() {
 324   return std::string(indentDepth, ' ');
 325 }
 326
 327 template<typename... Args>
 328 inline void itraceImpl(const char* fmtRaw, Args&&... args) {
 329   auto const fmt = indent() + fmtRaw;
 330   Trace::ftraceRelease(fmt, std::forward<Args>(args)...);
 331 }
 332 #define ITRACE(level, ...) ONTRACE((level), Trace::itraceImpl(__VA_ARGS__));
 333
 334 void trace(const char *, ...) ATTRIBUTE_PRINTF(1,2);
 335 void trace(const std::string&);
 336
 337 template<typename Pretty>
 338 inline void trace(Pretty p) { trace(p.pretty() + std::string("\n")); }
 339
 340 void vtrace(const char *fmt, va_list args) ATTRIBUTE_PRINTF(1,0);
 341 void dumpRingbuffer();
 342
 343 //////////////////////////////////////////////////////////////////////
 344
 345 #else /* } (defined(DEBUG) || defined(USE_TRACE)) { */
 346
 347 //////////////////////////////////////////////////////////////////////
 348 /*
 349  * Implementation for when tracing is disabled.
 350  */
 351
 352 #define ONTRACE(...)    do { } while (0)
 353 #define TRACE(...)      do { } while (0)
 354 #define FTRACE(...)     do { } while (0)
 355 #define TRACE_MOD(...)  do { } while (0)
 356 #define FTRACE_MOD(...) do { } while (0)
 357 #define TRACE_SET_MOD(name) \
 358   DEBUG_ONLY static const HPHP::Trace::Module TRACEMOD = HPHP::Trace::name;
 359
 360 #define ITRACE(...)     do { } while (0)
 361 struct Indent {
 362   Indent() {
 363     always_assert(true && "If this struct is completely empty we get unused "
 364                   "variable warnings in code that uses it.");
 365   }
 366 };
 367 inline std::string indent() { return std::string(); }
 368
 369 struct Bump {
 370   Bump(Module mod, int adjust, bool condition = true) {
 371     always_assert(true && "If this struct is completely empty we get unused "
 372                   "variable warnings in code that uses it.");
 373   }
 374 };
 375
 376 const bool enabled = false;
 377
 378 inline void trace(const char*, ...)      { }
 379 inline void trace(const std::string&)    { }
 380 inline void vtrace(const char*, va_list) { }
 381 inline bool moduleEnabled(Module t, int level = 1) { return false; }
 382 inline int moduleLevel(Module tm) { return 0; }
 383
 384 //////////////////////////////////////////////////////////////////////
 385
 386 #endif /* } (defined(DEBUG) || defined(USE_TRACE)) */
 387
 388 } // Trace
 389
 390 // Optional color utility for trace dumps; when output is a tty or
 391 // when we've been told to assume it is.
 392 inline const char* color(const char* color) {
 393   static auto const shouldColorize = []() -> bool {
 394     auto const traceEnv  = getenv("HPHP_TRACE_FILE");
 395     auto const assumeTTY = getenv("HPHP_TRACE_TTY");
 396     if (assumeTTY) return true;
 397     if (!traceEnv) return false;
 398     return
 399       !strcmp(traceEnv, "/dev/stdout") ? isatty(1) :
 400       !strcmp(traceEnv, "/dev/stderr") ? isatty(2) :
 401       false;
 402   }();
 403   return shouldColorize ? color : "";
 404 }
 405
 406 inline std::string color(const char* fg, const char* bg) {
 407   auto const s = add_bgcolor(fg, bg);
 408   return color(s.c_str());
 409 }
 410
 411 //////////////////////////////////////////////////////////////////////
 412
 413 FOLLY_CREATE_HAS_MEMBER_FN_TRAITS(has_toString, toString);
 414
 415 } // HPHP
 416
 417 namespace folly {
 418 template<typename Val>
 419 struct FormatValue<Val,
 420                    typename std::enable_if<
 421                      HPHP::has_toString<Val, std::string() const>::value,
 422                      void
 423                    >::type> {
 424   explicit FormatValue(const Val& val) : m_val(val) {}
 425
 426   template<typename Callback> void format(FormatArg& arg, Callback& cb) const {
 427     format_value::formatString(m_val.toString(), arg, cb);
 428   }
 429
 430  private:
 431   const Val& m_val;
 432 };
 433 }
 434
 435 #endif /* incl_HPHP_TRACE_H_ */
 436