| Line |
Branch |
Exec |
Source |
| 1 |
|
|
/** |
| 2 |
|
|
* This file is part of the CernVM File System. |
| 3 |
|
|
*/ |
| 4 |
|
|
|
| 5 |
|
|
#ifndef CVMFS_TRACER_H_ |
| 6 |
|
|
#define CVMFS_TRACER_H_ 1 |
| 7 |
|
|
|
| 8 |
|
|
#include <inttypes.h> |
| 9 |
|
|
#include <pthread.h> |
| 10 |
|
|
#include <sys/time.h> |
| 11 |
|
|
|
| 12 |
|
|
#include <cstdio> |
| 13 |
|
|
#include <string> |
| 14 |
|
|
|
| 15 |
|
|
#include "shortstring.h" |
| 16 |
|
|
#include "util/atomic.h" |
| 17 |
|
|
#include "util/single_copy.h" |
| 18 |
|
|
|
| 19 |
|
|
/** |
| 20 |
|
|
* Tracer is a thread-safe logging helper. It uses a ring buffer |
| 21 |
|
|
* and spawns a helper thread, that flushes the messages onto the disk |
| 22 |
|
|
* when necessary. The output file is in csv format. Usually tracing |
| 23 |
|
|
* a message is a lock-free process, which therefore should have minimal |
| 24 |
|
|
* overhead. |
| 25 |
|
|
* |
| 26 |
|
|
* This is _not_ supposed to be a debugging system. It is optimized for |
| 27 |
|
|
* speed and does not try to gather any additional information (like |
| 28 |
|
|
* threadid, status of variables, etc.). |
| 29 |
|
|
* |
| 30 |
|
|
* Csv output is adapted from libcsv. |
| 31 |
|
|
* |
| 32 |
|
|
* \todo If anything goes wrong, the whole thing breaks down on assertion. This |
| 33 |
|
|
* might be not desired behavior. |
| 34 |
|
|
*/ |
| 35 |
|
|
class Tracer : SingleCopy { |
| 36 |
|
|
public: |
| 37 |
|
|
enum TraceEvents { |
| 38 |
|
|
kEventOpen = 1, |
| 39 |
|
|
kEventOpenDir, |
| 40 |
|
|
kEventReadlink, |
| 41 |
|
|
kEventLookup, |
| 42 |
|
|
kEventStatFs, |
| 43 |
|
|
kEventGetAttr, |
| 44 |
|
|
kEventListAttr, |
| 45 |
|
|
kEventGetXAttr |
| 46 |
|
|
}; |
| 47 |
|
|
|
| 48 |
|
|
Tracer(); |
| 49 |
|
|
~Tracer(); |
| 50 |
|
|
|
| 51 |
|
|
void Activate(const int buffer_size, const int flush_threshold, |
| 52 |
|
|
const std::string &trace_file); |
| 53 |
|
|
void Spawn(); |
| 54 |
|
|
void Flush(); |
| 55 |
|
4423328 |
void inline __attribute__((used)) Trace(const int event, |
| 56 |
|
|
const PathString &path, |
| 57 |
|
|
const std::string &msg) { |
| 58 |
1/2
✓ Branch 0 taken 4425473 times.
✗ Branch 1 not taken.
|
4423328 |
if (active_) |
| 59 |
|
4425473 |
DoTrace(event, path, msg); |
| 60 |
|
4531345 |
} |
| 61 |
|
|
|
| 62 |
|
✗ |
bool inline __attribute__((used)) IsActive() { return active_; } |
| 63 |
|
|
|
| 64 |
|
|
private: |
| 65 |
|
|
/** |
| 66 |
|
|
* Code of the first log line in the trace file. |
| 67 |
|
|
*/ |
| 68 |
|
|
static const int kEventStart = -1; |
| 69 |
|
|
/** |
| 70 |
|
|
* Code of the last log line in the trace file. |
| 71 |
|
|
*/ |
| 72 |
|
|
static const int kEventStop = -2; |
| 73 |
|
|
/** |
| 74 |
|
|
* Manual flush |
| 75 |
|
|
*/ |
| 76 |
|
|
static const int kEventFlush = -3; |
| 77 |
|
|
|
| 78 |
|
|
/** |
| 79 |
|
|
* Contents of a single log line. |
| 80 |
|
|
*/ |
| 81 |
|
|
struct BufferEntry { |
| 82 |
|
|
/** |
| 83 |
|
|
* This is currently with milliseconds precision (using gettimeofday). |
| 84 |
|
|
*/ |
| 85 |
|
|
timeval time_stamp; |
| 86 |
|
|
/** |
| 87 |
|
|
* arbitrary code, negative codes are reserved for internal use. |
| 88 |
|
|
*/ |
| 89 |
|
|
int code; |
| 90 |
|
|
PathString path; /**< The path that is subject to the trace */ |
| 91 |
|
|
std::string msg; |
| 92 |
|
|
}; |
| 93 |
|
|
|
| 94 |
|
|
static void *MainFlush(void *data); |
| 95 |
|
|
void GetTimespecRel(const int64_t ms, timespec *ts); |
| 96 |
|
|
int WriteCsvFile(FILE *fp, const std::string &field); |
| 97 |
|
|
int32_t DoTrace(const int event, |
| 98 |
|
|
const PathString &path, |
| 99 |
|
|
const std::string &msg); |
| 100 |
|
|
|
| 101 |
|
|
bool active_; |
| 102 |
|
|
bool spawned_; |
| 103 |
|
|
std::string trace_file_; |
| 104 |
|
|
int buffer_size_; |
| 105 |
|
|
int flush_threshold_; |
| 106 |
|
|
BufferEntry *ring_buffer_; |
| 107 |
|
|
/** |
| 108 |
|
|
* Has the same size as the ring buffer. If a message is actually copied to |
| 109 |
|
|
* the ring buffer memory, the respective flag is set to 1. Flags are reset |
| 110 |
|
|
* to 0 by the flush thread. |
| 111 |
|
|
*/ |
| 112 |
|
|
atomic_int32 *commit_buffer_; |
| 113 |
|
|
pthread_t thread_flush_; |
| 114 |
|
|
pthread_cond_t sig_flush_; |
| 115 |
|
|
pthread_mutex_t sig_flush_mutex_; |
| 116 |
|
|
pthread_cond_t sig_continue_trace_; |
| 117 |
|
|
pthread_mutex_t sig_continue_trace_mutex_; |
| 118 |
|
|
/** |
| 119 |
|
|
* Starts with 0 and gets incremented by each call to trace. Contains the |
| 120 |
|
|
* first non-used sequence number. |
| 121 |
|
|
*/ |
| 122 |
|
|
atomic_int32 seq_no_; |
| 123 |
|
|
/** |
| 124 |
|
|
* Starts with 0 and gets incremented by the flush thread. Points to the |
| 125 |
|
|
* first non-flushed message. flushed <= seq_no holds. |
| 126 |
|
|
*/ |
| 127 |
|
|
atomic_int32 flushed_; |
| 128 |
|
|
atomic_int32 terminate_flush_thread_; |
| 129 |
|
|
atomic_int32 flush_immediately_; |
| 130 |
|
|
}; |
| 131 |
|
|
|
| 132 |
|
|
#endif // CVMFS_TRACER_H_ |
| 133 |
|
|
|