Use system-wide thread ID in info log lines (#9164)

Summary:
This makes it easier to debug with tools like `ps`. The change only
applies to builds with glibc 2.30+ and _GNU_SOURCE extensions enabled.
We could adopt it in more cases by using the syscall but this is enough
for our build.

Replaces https://github.com/facebook/rocksdb/issues/2973.

Pull Request resolved: https://github.com/facebook/rocksdb/pull/9164

Test Plan:
- ran some benchmarks and correlated logged thread IDs with those shown by `ps -L`.
- verified no noticeable regression in throughput for log heavy (more than 700k log lines and over 5k / second) scenario.

Benchmark command:

```
$ TEST_TMPDIR=/dev/shm ./db_bench -benchmarks=filluniquerandom -compression_type=none -max_bytes_for_level_multiplier=2 -write_buffer_size=262144 -num_levels=7 -max_bytes_for_level_base=2097152 -target_file_size_base=524288 -level_compaction_dynamic_level_bytes=true -max_background_jobs=12 -num=20000000
```

Results before: 15.9MB/s, 15.8MB/s, 16.0MB/s
Results after: 16.3MB/s, 16.3MB/s, 15.8MB/s

- Rely on CI to test the fallback behavior

Reviewed By: riversand963

Differential Revision: D32399660

Pulled By: ajkr

fbshipit-source-id: c24d44fdf7782faa616ef0a0964eaca3539d9c24
main
Andrew Kryczka 3 years ago committed by Facebook GitHub Bot
parent 3295e9f640
commit 9bb13c56b3
  1. 1
      HISTORY.md
  2. 21
      env/env_posix.cc
  3. 12
      logging/posix_logger.h

@ -21,6 +21,7 @@
### Public Interface Change ### Public Interface Change
* When options.ttl is used with leveled compaction with compactinon priority kMinOverlappingRatio, files exceeding half of TTL value will be prioritized more, so that by the time TTL is reached, fewer extra compactions will be scheduled to clear them up. At the same time, when compacting files with data older than half of TTL, output files may be cut off based on those files' boundaries, in order for the early TTL compaction to work properly. * When options.ttl is used with leveled compaction with compactinon priority kMinOverlappingRatio, files exceeding half of TTL value will be prioritized more, so that by the time TTL is reached, fewer extra compactions will be scheduled to clear them up. At the same time, when compacting files with data older than half of TTL, output files may be cut off based on those files' boundaries, in order for the early TTL compaction to work properly.
* Info log ("LOG" file) lines now print a system-wide thread ID from `gettid()` when the compiler flags/glibc version make it available instead of the process-local `pthread_self()`. For all users, the thread ID format is changed from hexadecimal to decimal integer.
### Public API change ### Public API change
* Made FileSystem extend the Customizable class and added a CreateFromString method. Implementations need to be registered with the ObjectRegistry and to implement a Name() method in order to be created via this method. * Made FileSystem extend the Customizable class and added a CreateFromString method. Implementations need to be registered with the ObjectRegistry and to implement a Name() method in order to be created via this method.

21
env/env_posix.cc vendored

@ -37,6 +37,8 @@
#include <sys/uio.h> #include <sys/uio.h>
#endif #endif
#include <time.h> #include <time.h>
#include <unistd.h>
#include <algorithm> #include <algorithm>
// Get nano time includes // Get nano time includes
#if defined(OS_LINUX) || defined(OS_FREEBSD) || defined(OS_GNU_KFREEBSD) #if defined(OS_LINUX) || defined(OS_FREEBSD) || defined(OS_GNU_KFREEBSD)
@ -302,19 +304,22 @@ class PosixEnv : public CompositeEnv {
return thread_status_updater_->GetThreadList(thread_list); return thread_status_updater_->GetThreadList(thread_list);
} }
static uint64_t gettid(pthread_t tid) { uint64_t GetThreadID() const override {
uint64_t thread_id = 0; uint64_t thread_id = 0;
#if defined(_GNU_SOURCE) && defined(__GLIBC_PREREQ)
#if __GLIBC_PREREQ(2, 30)
thread_id = ::gettid();
#else // __GLIBC_PREREQ(2, 30)
pthread_t tid = pthread_self();
memcpy(&thread_id, &tid, std::min(sizeof(thread_id), sizeof(tid))); memcpy(&thread_id, &tid, std::min(sizeof(thread_id), sizeof(tid)));
return thread_id; #endif // __GLIBC_PREREQ(2, 30)
} #else // defined(_GNU_SOURCE) && defined(__GLIBC_PREREQ)
static uint64_t gettid() {
pthread_t tid = pthread_self(); pthread_t tid = pthread_self();
return gettid(tid); memcpy(&thread_id, &tid, std::min(sizeof(thread_id), sizeof(tid)));
#endif // defined(_GNU_SOURCE) && defined(__GLIBC_PREREQ)
return thread_id;
} }
uint64_t GetThreadID() const override { return gettid(pthread_self()); }
Status GetHostName(char* name, uint64_t len) override { Status GetHostName(char* name, uint64_t len) override {
int ret = gethostname(name, static_cast<size_t>(len)); int ret = gethostname(name, static_cast<size_t>(len));
if (ret < 0) { if (ret < 0) {

@ -108,15 +108,9 @@ class PosixLogger : public Logger {
const time_t seconds = now_tv.tv_sec; const time_t seconds = now_tv.tv_sec;
struct tm t; struct tm t;
localtime_r(&seconds, &t); localtime_r(&seconds, &t);
p += snprintf(p, limit - p, p += snprintf(p, limit - p, "%04d/%02d/%02d-%02d:%02d:%02d.%06d %llu ",
"%04d/%02d/%02d-%02d:%02d:%02d.%06d %llx ", t.tm_year + 1900, t.tm_mon + 1, t.tm_mday, t.tm_hour,
t.tm_year + 1900, t.tm_min, t.tm_sec, static_cast<int>(now_tv.tv_usec),
t.tm_mon + 1,
t.tm_mday,
t.tm_hour,
t.tm_min,
t.tm_sec,
static_cast<int>(now_tv.tv_usec),
static_cast<long long unsigned int>(thread_id)); static_cast<long long unsigned int>(thread_id));
// Print the message // Print the message

Loading…
Cancel
Save