tests/clar_libgit2_trace.c

   1 #include "clar_libgit2.h"
   2 #include "clar_libgit2_trace.h"
   3 #include "clar_libgit2_timer.h"
   4 #include "trace.h"
   5
   6
   7 struct method {
   8         const char *name;
   9         void (*git_trace_cb)(git_trace_level_t level, const char *msg);
  10         void (*close)(void);
  11 };
  12
  13
  14 #if defined(GIT_TRACE)
  15 static void _git_trace_cb__printf(git_trace_level_t level, const char *msg)
  16 {
  17         /* TODO Use level to print a per-message prefix. */
  18         GIT_UNUSED(level);
  19
  20         printf("%s\n", msg);
  21 }
  22
  23 #if defined(GIT_WIN32)
  24 static void _git_trace_cb__debug(git_trace_level_t level, const char *msg)
  25 {
  26         /* TODO Use level to print a per-message prefix. */
  27         GIT_UNUSED(level);
  28
  29         OutputDebugString(msg);
  30         OutputDebugString("\n");
  31
  32         printf("%s\n", msg);
  33 }
  34 #else
  35 #define _git_trace_cb__debug _git_trace_cb__printf
  36 #endif
  37
  38
  39 static void _trace_printf_close(void)
  40 {
  41         fflush(stdout);
  42 }
  43
  44 #define _trace_debug_close _trace_printf_close
  45
  46
  47 static struct method s_methods[] = {
  48         { "printf", _git_trace_cb__printf, _trace_printf_close },
  49         { "debug",  _git_trace_cb__debug,  _trace_debug_close  },
  50         /* TODO add file method */
  51         {0},
  52 };
  53
  54
  55 static int s_trace_loaded = 0;
  56 static int s_trace_level = GIT_TRACE_NONE;
  57 static struct method *s_trace_method = NULL;
  58
  59
  60 static int set_method(const char *name)
  61 {
  62         int k;
  63
  64         if (!name || !*name)
  65                 name = "printf";
  66
  67         for (k=0; (s_methods[k].name); k++) {
  68                 if (strcmp(name, s_methods[k].name) == 0) {
  69                         s_trace_method = &s_methods[k];
  70                         return 0;
  71                 }
  72         }
  73         fprintf(stderr, "Unknown CLAR_TRACE_METHOD: '%s'\n", name);
  74         return -1;
  75 }
  76
  77
  78 /**
  79  * Lookup CLAR_TRACE_LEVEL and CLAR_TRACE_METHOD from
  80  * the environment and set the above s_trace_* fields.
  81  *
  82  * If CLAR_TRACE_LEVEL is not set, we disable tracing.
  83  *
  84  * TODO If set, we assume GIT_TRACE_TRACE level, which
  85  * logs everything. Later, we may want to parse the
  86  * value of the environment variable and set a specific
  87  * level.
  88  *
  89  * We assume the "printf" method.  This can be changed
  90  * with the CLAR_TRACE_METHOD environment variable.
  91  * Currently, this is only needed on Windows for a "debug"
  92  * version which also writes to the debug output window
  93  * in Visual Studio.
  94  *
  95  * TODO add a "file" method that would open and write
  96  * to a well-known file. This would help keep trace
  97  * output and clar output separate.
  98  *
  99  */
 100 static void _load_trace_params(void)
 101 {
 102         char *sz_level;
 103         char *sz_method;
 104
 105         s_trace_loaded = 1;
 106
 107         sz_level = cl_getenv("CLAR_TRACE_LEVEL");
 108         if (!sz_level || !*sz_level) {
 109                 s_trace_level = GIT_TRACE_NONE;
 110                 s_trace_method = NULL;
 111                 return;
 112         }
 113
 114         /* TODO Parse sz_level and set s_trace_level. */
 115         s_trace_level = GIT_TRACE_TRACE;
 116
 117         sz_method = cl_getenv("CLAR_TRACE_METHOD");
 118         if (set_method(sz_method) < 0)
 119                 set_method(NULL);
 120 }
 121
 122 #define HR "================================================================"
 123
 124 /**
 125  * Timer to report the take spend in a test's run() method.
 126  */
 127 static cl_perf_timer s_timer_run = CL_PERF_TIMER_INIT;
 128
 129 /**
 130  * Timer to report total time in a test (init, run, cleanup).
 131  */
 132 static cl_perf_timer s_timer_test = CL_PERF_TIMER_INIT;
 133
 134 void _cl_trace_cb__event_handler(
 135         cl_trace_event ev,
 136         const char *suite_name,
 137         const char *test_name,
 138         void *payload)
 139 {
 140         GIT_UNUSED(payload);
 141
 142         switch (ev) {
 143         case CL_TRACE__SUITE_BEGIN:
 144                 git_trace(GIT_TRACE_TRACE, "\n\n%s\n%s: Begin Suite", HR, suite_name);
 145 #if 0 && defined(GIT_MSVC_CRTDBG)
 146                 git_win32__crtdbg_stacktrace__dump(
 147                         GIT_WIN32__CRTDBG_STACKTRACE__SET_MARK,
 148                         suite_name);
 149 #endif
 150                 break;
 151
 152         case CL_TRACE__SUITE_END:
 153 #if 0 && defined(GIT_MSVC_CRTDBG)
 154                 /* As an example of checkpointing, dump leaks within this suite.
 155                  * This may generate false positives for things like the global
 156                  * TLS error state and maybe the odb cache since they aren't
 157                  * freed until the global shutdown and outside the scope of this
 158                  * set of tests.
 159                  *
 160                  * This may under-report if the test itself uses a checkpoint.
 161                  * See tests/trace/windows/stacktrace.c
 162                  */
 163                 git_win32__crtdbg_stacktrace__dump(
 164                         GIT_WIN32__CRTDBG_STACKTRACE__LEAKS_SINCE_MARK,
 165                         suite_name);
 166 #endif
 167                 git_trace(GIT_TRACE_TRACE, "\n\n%s: End Suite\n%s", suite_name, HR);
 168                 break;
 169
 170         case CL_TRACE__TEST__BEGIN:
 171                 git_trace(GIT_TRACE_TRACE, "\n%s::%s: Begin Test", suite_name, test_name);
 172                 cl_perf_timer__init(&s_timer_test);
 173                 cl_perf_timer__start(&s_timer_test);
 174                 break;
 175
 176         case CL_TRACE__TEST__END:
 177                 cl_perf_timer__stop(&s_timer_test);
 178                 git_trace(GIT_TRACE_TRACE, "%s::%s: End Test (%.3f %.3f)", suite_name, test_name,
 179                                   cl_perf_timer__last(&s_timer_run),
 180                                   cl_perf_timer__last(&s_timer_test));
 181                 break;
 182
 183         case CL_TRACE__TEST__RUN_BEGIN:
 184                 git_trace(GIT_TRACE_TRACE, "%s::%s: Begin Run", suite_name, test_name);
 185                 cl_perf_timer__init(&s_timer_run);
 186                 cl_perf_timer__start(&s_timer_run);
 187                 break;
 188
 189         case CL_TRACE__TEST__RUN_END:
 190                 cl_perf_timer__stop(&s_timer_run);
 191                 git_trace(GIT_TRACE_TRACE, "%s::%s: End Run", suite_name, test_name);
 192                 break;
 193
 194         case CL_TRACE__TEST__LONGJMP:
 195                 cl_perf_timer__stop(&s_timer_run);
 196                 git_trace(GIT_TRACE_TRACE, "%s::%s: Aborted", suite_name, test_name);
 197                 break;
 198
 199         default:
 200                 break;
 201         }
 202 }
 203
 204 #endif /*GIT_TRACE*/
 205
 206 /**
 207  * Setup/Enable git_trace() based upon settings user's environment.
 208  *
 209  */
 210 void cl_global_trace_register(void)
 211 {
 212 #if defined(GIT_TRACE)
 213         if (!s_trace_loaded)
 214                 _load_trace_params();
 215
 216         if (s_trace_level == GIT_TRACE_NONE)
 217                 return;
 218         if (s_trace_method == NULL)
 219                 return;
 220         if (s_trace_method->git_trace_cb == NULL)
 221                 return;
 222
 223         git_trace_set(s_trace_level, s_trace_method->git_trace_cb);
 224         cl_trace_register(_cl_trace_cb__event_handler, NULL);
 225 #endif
 226 }
 227
 228 /**
 229  * If we turned on git_trace() earlier, turn it off.
 230  *
 231  * This is intended to let us close/flush any buffered
 232  * IO if necessary.
 233  *
 234  */
 235 void cl_global_trace_disable(void)
 236 {
 237 #if defined(GIT_TRACE)
 238         cl_trace_register(NULL, NULL);
 239         git_trace_set(GIT_TRACE_NONE, NULL);
 240         if (s_trace_method && s_trace_method->close)
 241                 s_trace_method->close();
 242
 243         /* Leave s_trace_ vars set so they can restart tracing
 244          * since we only want to hit the environment variables
 245          * once.
 246          */
 247 #endif
 248 }