Coverage Report

Created: 2023-11-19 06:38

/src/brpc/src/butil/logging.cc
Line
Count
Source (jump to first uncovered line)
1
// Licensed to the Apache Software Foundation (ASF) under one
2
// or more contributor license agreements.  See the NOTICE file
3
// distributed with this work for additional information
4
// regarding copyright ownership.  The ASF licenses this file
5
// to you under the Apache License, Version 2.0 (the
6
// "License"); you may not use this file except in compliance
7
// with the License.  You may obtain a copy of the License at
8
//
9
//   http://www.apache.org/licenses/LICENSE-2.0
10
//
11
// Unless required by applicable law or agreed to in writing,
12
// software distributed under the License is distributed on an
13
// "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
14
// KIND, either express or implied.  See the License for the
15
// specific language governing permissions and limitations
16
// under the License.
17
18
// Date: 2012-10-08 23:53:50
19
20
#include "butil/logging.h"
21
22
#include <gflags/gflags.h>
23
DEFINE_bool(log_as_json, false, "Print log as a valid JSON");
24
DEFINE_bool(escape_log, false, "Escape log content before printing");
25
26
#if !BRPC_WITH_GLOG
27
28
#if defined(OS_WIN)
29
#include <io.h>
30
#include <windows.h>
31
typedef HANDLE FileHandle;
32
typedef HANDLE MutexHandle;
33
// Windows warns on using write().  It prefers _write().
34
#define write(fd, buf, count) _write(fd, buf, static_cast<unsigned int>(count))
35
// Windows doesn't define STDERR_FILENO.  Define it here.
36
#define STDERR_FILENO 2
37
#elif defined(OS_MACOSX)
38
#include <mach/mach.h>
39
#include <mach/mach_time.h>
40
#include <mach-o/dyld.h>
41
#elif defined(OS_POSIX)
42
#if defined(OS_NACL) || defined(OS_LINUX)
43
#include <sys/time.h> // timespec doesn't seem to be in <time.h>
44
#else
45
#include <sys/syscall.h>
46
#endif
47
#include <time.h>
48
#endif
49
#if defined(OS_POSIX)
50
#include <errno.h>
51
#include <pthread.h>
52
#include <stdio.h>
53
#include <stdlib.h>
54
#include <string.h>
55
#include <unistd.h>
56
#define MAX_PATH PATH_MAX
57
typedef FILE* FileHandle;
58
typedef pthread_mutex_t* MutexHandle;
59
#endif
60
61
#include <algorithm>
62
#include <cstring>
63
#include <ctime>
64
#include <iomanip>
65
#include <ostream>
66
#include <string>
67
68
#include "butil/file_util.h"
69
#include "butil/debug/alias.h"
70
#include "butil/debug/debugger.h"
71
#include "butil/debug/stack_trace.h"
72
#include "butil/posix/eintr_wrapper.h"
73
#include "butil/strings/string_util.h"
74
#include "butil/strings/stringprintf.h"
75
#include "butil/strings/utf_string_conversions.h"
76
#include "butil/synchronization/lock.h"
77
#include "butil/threading/platform_thread.h"
78
#if defined(OS_POSIX)
79
#include "butil/errno.h"
80
#include "butil/fd_guard.h"
81
#endif
82
#if defined(OS_LINUX)
83
#include <fcntl.h>
84
#endif
85
86
#if defined(OS_ANDROID)
87
#include <android/log.h>
88
#endif
89
90
#include <map>
91
#include <vector>
92
#include <deque>
93
#include <limits>
94
#include "butil/atomicops.h"
95
#include "butil/thread_local.h"
96
#include "butil/scoped_lock.h"                        // BAIDU_SCOPED_LOCK
97
#include "butil/string_splitter.h"
98
#include "butil/time.h"
99
#include "butil/containers/doubly_buffered_data.h"
100
#include "butil/memory/singleton.h"
101
#include "butil/endpoint.h"
102
#ifdef BAIDU_INTERNAL
103
#include "butil/comlog_sink.h"
104
#endif
105
106
extern "C" {
107
uint64_t BAIDU_WEAK bthread_self();
108
typedef struct {
109
    uint32_t index;    // index in KeyTable
110
    uint32_t version;  // ABA avoidance
111
} bthread_key_t;
112
int BAIDU_WEAK bthread_key_create(bthread_key_t* key,
113
                                  void (*destructor)(void* data));
114
int BAIDU_WEAK bthread_setspecific(bthread_key_t key, void* data);
115
void* BAIDU_WEAK bthread_getspecific(bthread_key_t key);
116
}
117
118
namespace logging {
119
120
DEFINE_bool(crash_on_fatal_log, false,
121
            "Crash process when a FATAL log is printed");
122
DEFINE_bool(print_stack_on_check, true,
123
            "Print the stack trace when a CHECK was failed");
124
125
DEFINE_int32(v, 0, "Show all VLOG(m) messages for m <= this."
126
             " Overridable by --vmodule.");
127
DEFINE_string(vmodule, "", "per-module verbose level."
128
              " Argument is a comma-separated list of MODULE_NAME=LOG_LEVEL."
129
              " MODULE_NAME is a glob pattern, matched against the filename base"
130
              " (that is, name ignoring .cpp/.h)."
131
              " LOG_LEVEL overrides any value given by --v.");
132
133
DEFINE_bool(log_pid, false, "Log process id");
134
135
DEFINE_int32(minloglevel, 0, "Any log at or above this level will be "
136
             "displayed. Anything below this level will be silently ignored. "
137
             "0=INFO 1=NOTICE 2=WARNING 3=ERROR 4=FATAL");
138
139
DEFINE_bool(log_hostname, false, "Add host after pid in each log so"
140
            " that we know where logs came from when using aggregation tools"
141
            " like ELK.");
142
143
DEFINE_bool(log_year, false, "Log year in datetime part in each log");
144
145
DEFINE_bool(log_func_name, false, "Log function name in each log");
146
147
namespace {
148
149
LoggingDestination logging_destination = LOG_DEFAULT;
150
151
// For BLOG_ERROR and above, always print to stderr.
152
const int kAlwaysPrintErrorLevel = BLOG_ERROR;
153
154
// Which log file to use? This is initialized by InitLogging or
155
// will be lazily initialized to the default value when it is
156
// first needed.
157
#if defined(OS_WIN)
158
typedef std::wstring PathString;
159
#else
160
typedef std::string PathString;
161
#endif
162
PathString* log_file_name = NULL;
163
164
// this file is lazily opened and the handle may be NULL
165
FileHandle log_file = NULL;
166
167
// Should we pop up fatal debug messages in a dialog?
168
bool show_error_dialogs = false;
169
170
// An assert handler override specified by the client to be called instead of
171
// the debug message dialog and process termination.
172
LogAssertHandler log_assert_handler = NULL;
173
174
// Helper functions to wrap platform differences.
175
176
0
int32_t CurrentProcessId() {
177
#if defined(OS_WIN)
178
    return GetCurrentProcessId();
179
#elif defined(OS_POSIX)
180
0
    return getpid();
181
0
#endif
182
0
}
183
184
0
void DeleteFilePath(const PathString& log_name) {
185
#if defined(OS_WIN)
186
    DeleteFile(log_name.c_str());
187
#elif defined (OS_NACL)
188
    // Do nothing; unlink() isn't supported on NaCl.
189
#else
190
0
    unlink(log_name.c_str());
191
0
#endif
192
0
}
193
194
#if defined(OS_LINUX)
195
0
static PathString GetProcessName() {
196
0
    butil::fd_guard fd(open("/proc/self/cmdline", O_RDONLY));
197
0
    if (fd < 0) {
198
0
        return "unknown";
199
0
    }
200
0
    char buf[512];
201
0
    const ssize_t len = read(fd, buf, sizeof(buf) - 1);
202
0
    if (len <= 0) {
203
0
        return "unknown";
204
0
    }
205
0
    buf[len] = '\0';
206
    // Not string(buf, len) because we needs to buf to be truncated at first \0.
207
    // Under gdb, the first part of cmdline may include path.
208
0
    return butil::FilePath(std::string(buf)).BaseName().value();
209
0
}
210
#endif
211
212
0
PathString GetDefaultLogFile() {
213
#if defined(OS_WIN)
214
    // On Windows we use the same path as the exe.
215
    wchar_t module_name[MAX_PATH];
216
    GetModuleFileName(NULL, module_name, MAX_PATH);
217
218
    PathString log_file = module_name;
219
    PathString::size_type last_backslash =
220
        log_file.rfind('\\', log_file.size());
221
    if (last_backslash != PathString::npos)
222
        log_file.erase(last_backslash + 1);
223
    log_file += L"debug.log";
224
    return log_file;
225
#elif defined(OS_LINUX)
226
0
    return GetProcessName() + ".log";
227
#elif defined(OS_POSIX)    
228
    // On other platforms we just use the current directory.
229
    return PathString("debug.log");
230
#endif
231
0
}
232
233
// This class acts as a wrapper for locking the logging files.
234
// LoggingLock::Init() should be called from the main thread before any logging
235
// is done. Then whenever logging, be sure to have a local LoggingLock
236
// instance on the stack. This will ensure that the lock is unlocked upon
237
// exiting the frame.
238
// LoggingLocks can not be nested.
239
class LoggingLock {
240
public:
241
0
    LoggingLock() {
242
0
        LockLogging();
243
0
    }
244
245
0
    ~LoggingLock() {
246
0
        UnlockLogging();
247
0
    }
248
249
0
    static void Init(LogLockingState lock_log, const LogChar* new_log_file) {
250
0
        if (initialized)
251
0
            return;
252
0
        lock_log_file = lock_log;
253
0
        if (lock_log_file == LOCK_LOG_FILE) {
254
#if defined(OS_WIN)
255
            if (!log_mutex) {
256
                std::wstring safe_name;
257
                if (new_log_file)
258
                    safe_name = new_log_file;
259
                else
260
                    safe_name = GetDefaultLogFile();
261
                // \ is not a legal character in mutex names so we replace \ with /
262
                std::replace(safe_name.begin(), safe_name.end(), '\\', '/');
263
                std::wstring t(L"Global\\");
264
                t.append(safe_name);
265
                log_mutex = ::CreateMutex(NULL, FALSE, t.c_str());
266
267
                if (log_mutex == NULL) {
268
#if DEBUG
269
                    // Keep the error code for debugging
270
                    int error = GetLastError();  // NOLINT
271
                    butil::debug::BreakDebugger();
272
#endif
273
                    // Return nicely without putting initialized to true.
274
                    return;
275
                }
276
            }
277
#endif
278
0
        } else {
279
0
            log_lock = new butil::Mutex;
280
0
        }
281
0
        initialized = true;
282
0
    }
283
284
private:
285
0
    static void LockLogging() {
286
0
        if (lock_log_file == LOCK_LOG_FILE) {
287
#if defined(OS_WIN)
288
            ::WaitForSingleObject(log_mutex, INFINITE);
289
            // WaitForSingleObject could have returned WAIT_ABANDONED. We don't
290
            // abort the process here. UI tests might be crashy sometimes,
291
            // and aborting the test binary only makes the problem worse.
292
            // We also don't use LOG macros because that might lead to an infinite
293
            // loop. For more info see http://crbug.com/18028.
294
#elif defined(OS_POSIX)
295
0
            pthread_mutex_lock(&log_mutex);
296
0
#endif
297
0
        } else {
298
            // use the lock
299
0
            log_lock->lock();
300
0
        }
301
0
    }
302
303
0
    static void UnlockLogging() {
304
0
        if (lock_log_file == LOCK_LOG_FILE) {
305
#if defined(OS_WIN)
306
            ReleaseMutex(log_mutex);
307
#elif defined(OS_POSIX)
308
0
            pthread_mutex_unlock(&log_mutex);
309
0
#endif
310
0
        } else {
311
0
            log_lock->unlock();
312
0
        }
313
0
    }
314
315
    // The lock is used if log file locking is false. It helps us avoid problems
316
    // with multiple threads writing to the log file at the same time.
317
    static butil::Mutex* log_lock;
318
319
    // When we don't use a lock, we are using a global mutex. We need to do this
320
    // because LockFileEx is not thread safe.
321
#if defined(OS_WIN)
322
    static MutexHandle log_mutex;
323
#elif defined(OS_POSIX)
324
    static pthread_mutex_t log_mutex;
325
#endif
326
327
    static bool initialized;
328
    static LogLockingState lock_log_file;
329
};
330
331
// static
332
bool LoggingLock::initialized = false;
333
// static
334
butil::Mutex* LoggingLock::log_lock = NULL;
335
// static
336
LogLockingState LoggingLock::lock_log_file = LOCK_LOG_FILE;
337
338
#if defined(OS_WIN)
339
// static
340
MutexHandle LoggingLock::log_mutex = NULL;
341
#elif defined(OS_POSIX)
342
pthread_mutex_t LoggingLock::log_mutex = PTHREAD_MUTEX_INITIALIZER;
343
#endif
344
345
// Called by logging functions to ensure that debug_file is initialized
346
// and can be used for writing. Returns false if the file could not be
347
// initialized. debug_file will be NULL in this case.
348
0
bool InitializeLogFileHandle() {
349
0
    if (log_file)
350
0
        return true;
351
352
0
    if (!log_file_name) {
353
        // Nobody has called InitLogging to specify a debug log file, so here we
354
        // initialize the log file name to a default.
355
0
        log_file_name = new PathString(GetDefaultLogFile());
356
0
    }
357
358
0
    if ((logging_destination & LOG_TO_FILE) != 0) {
359
#if defined(OS_WIN)
360
        log_file = CreateFile(log_file_name->c_str(), GENERIC_WRITE,
361
                              FILE_SHARE_READ | FILE_SHARE_WRITE, NULL,
362
                              OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, NULL);
363
        if (log_file == INVALID_HANDLE_VALUE || log_file == NULL) {
364
            // try the current directory
365
            log_file = CreateFile(L".\\debug.log", GENERIC_WRITE,
366
                                  FILE_SHARE_READ | FILE_SHARE_WRITE, NULL,
367
                                  OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, NULL);
368
            if (log_file == INVALID_HANDLE_VALUE || log_file == NULL) {
369
                log_file = NULL;
370
                return false;
371
            }
372
        }
373
        SetFilePointer(log_file, 0, 0, FILE_END);
374
#elif defined(OS_POSIX)
375
0
        log_file = fopen(log_file_name->c_str(), "a");
376
0
        if (log_file == NULL) {
377
0
            fprintf(stderr, "Fail to fopen %s", log_file_name->c_str());
378
0
            return false;
379
0
        }
380
0
#endif
381
0
    }
382
383
0
    return true;
384
0
}
385
386
0
void CloseFile(FileHandle log) {
387
#if defined(OS_WIN)
388
    CloseHandle(log);
389
#else
390
0
    fclose(log);
391
0
#endif
392
0
}
393
394
0
void CloseLogFileUnlocked() {
395
0
    if (!log_file)
396
0
        return;
397
398
0
    CloseFile(log_file);
399
0
    log_file = NULL;
400
0
}
401
402
}  // namespace
403
404
LoggingSettings::LoggingSettings()
405
    : logging_dest(LOG_DEFAULT),
406
      log_file(NULL),
407
      lock_log(LOCK_LOG_FILE),
408
0
      delete_old(APPEND_TO_OLD_LOG_FILE) {}
409
410
0
bool BaseInitLoggingImpl(const LoggingSettings& settings) {
411
#if defined(OS_NACL)
412
    // Can log only to the system debug log.
413
    CHECK_EQ(settings.logging_dest & ~LOG_TO_SYSTEM_DEBUG_LOG, 0);
414
#endif
415
416
0
    logging_destination = settings.logging_dest;
417
418
    // ignore file options unless logging to file is set.
419
0
    if ((logging_destination & LOG_TO_FILE) == 0)
420
0
        return true;
421
422
0
    LoggingLock::Init(settings.lock_log, settings.log_file);
423
0
    LoggingLock logging_lock;
424
425
    // Calling InitLogging twice or after some log call has already opened the
426
    // default log file will re-initialize to the new options.
427
0
    CloseLogFileUnlocked();
428
429
0
    if (!log_file_name)
430
0
        log_file_name = new PathString();
431
0
    if (settings.log_file) {
432
0
        *log_file_name = settings.log_file;
433
0
    } else {
434
0
        *log_file_name = GetDefaultLogFile();
435
0
    }
436
0
    if (settings.delete_old == DELETE_OLD_LOG_FILE)
437
0
        DeleteFilePath(*log_file_name);
438
439
0
    return InitializeLogFileHandle();
440
0
}
441
442
0
void SetMinLogLevel(int level) {
443
0
    FLAGS_minloglevel = std::min(BLOG_FATAL, level);
444
0
}
445
446
3.42k
int GetMinLogLevel() {
447
3.42k
    return FLAGS_minloglevel;
448
3.42k
}
449
450
0
void SetShowErrorDialogs(bool enable_dialogs) {
451
0
    show_error_dialogs = enable_dialogs;
452
0
}
453
454
0
void SetLogAssertHandler(LogAssertHandler handler) {
455
0
    log_assert_handler = handler;
456
0
}
457
458
const char* const log_severity_names[LOG_NUM_SEVERITIES] = {
459
    "INFO", "NOTICE", "WARNING", "ERROR", "FATAL" };
460
461
3.42k
static void PrintLogSeverity(std::ostream& os, int severity) {
462
3.42k
    if (severity < 0) {
463
        // Add extra space to separate from following datetime.
464
0
        os << 'V' << -severity << ' ';
465
3.42k
    } else if (severity < LOG_NUM_SEVERITIES) {
466
3.42k
        os << log_severity_names[severity][0];
467
3.42k
    } else {
468
0
        os << 'U';
469
0
    }
470
3.42k
}
471
472
void PrintLogPrefix(std::ostream& os, int severity,
473
                    const char* file, int line,
474
3.42k
                    const char* func) {
475
3.42k
    PrintLogSeverity(os, severity);
476
3.42k
#if defined(OS_LINUX)
477
3.42k
    timeval tv;
478
3.42k
    gettimeofday(&tv, NULL);
479
3.42k
    time_t t = tv.tv_sec;
480
#else
481
    time_t t = time(NULL);
482
#endif
483
3.42k
    struct tm local_tm = {0, 0, 0, 0, 0, 0, 0, 0, 0, 0, NULL};
484
#if _MSC_VER >= 1400
485
    localtime_s(&local_tm, &t);
486
#else
487
3.42k
    localtime_r(&t, &local_tm);
488
3.42k
#endif
489
3.42k
    const char prev_fill = os.fill('0');
490
3.42k
    if (FLAGS_log_year) {
491
0
        os << std::setw(4) << local_tm.tm_year + 1900;
492
0
    }
493
3.42k
    os << std::setw(2) << local_tm.tm_mon + 1
494
3.42k
       << std::setw(2) << local_tm.tm_mday << ' '
495
3.42k
       << std::setw(2) << local_tm.tm_hour << ':'
496
3.42k
       << std::setw(2) << local_tm.tm_min << ':'
497
3.42k
       << std::setw(2) << local_tm.tm_sec;
498
3.42k
#if defined(OS_LINUX)
499
3.42k
    os << '.' << std::setw(6) << tv.tv_usec;
500
3.42k
#endif
501
3.42k
    if (FLAGS_log_pid) {
502
0
        os << ' ' << std::setfill(' ') << std::setw(5) << CurrentProcessId();
503
0
    }
504
3.42k
    os << ' ' << std::setfill(' ') << std::setw(5)
505
3.42k
       << butil::PlatformThread::CurrentId() << std::setfill('0');
506
3.42k
    if (FLAGS_log_hostname) {
507
0
        butil::StringPiece hostname(butil::my_hostname());
508
0
        if (hostname.ends_with(".baidu.com")) { // make it shorter
509
0
            hostname.remove_suffix(10);
510
0
        }
511
0
        os << ' ' << hostname;
512
0
    }
513
3.42k
    os << ' ' << file << ':' << line;
514
3.42k
    if (func && *func != '\0') {
515
0
        os << " " << func;
516
0
    }
517
3.42k
    os << "] ";
518
519
3.42k
    os.fill(prev_fill);
520
3.42k
}
521
522
void PrintLogPrefix(std::ostream& os, int severity,
523
0
                    const char* file, int line) {
524
0
    PrintLogPrefix(os, severity, file, line, "");
525
0
}
526
527
static void PrintLogPrefixAsJSON(std::ostream& os, int severity,
528
                                 const char* file, const char* func,
529
0
                                 int line) {
530
    // severity
531
0
    os << "\"L\":\"";
532
0
    if (severity < 0) {
533
0
        os << 'V' << -severity;
534
0
    } else if (severity < LOG_NUM_SEVERITIES) {
535
0
        os << log_severity_names[severity][0];
536
0
    } else {
537
0
        os << 'U';
538
0
    }
539
    // time
540
0
    os << "\",\"T\":\"";
541
0
#if defined(OS_LINUX)
542
0
    timeval tv;
543
0
    gettimeofday(&tv, NULL);
544
0
    time_t t = tv.tv_sec;
545
#else
546
    time_t t = time(NULL);
547
#endif
548
0
    struct tm local_tm = {0, 0, 0, 0, 0, 0, 0, 0, 0, 0, NULL};
549
#if _MSC_VER >= 1400
550
    localtime_s(&local_tm, &t);
551
#else
552
0
    localtime_r(&t, &local_tm);
553
0
#endif
554
0
    const char prev_fill = os.fill('0');
555
0
    if (FLAGS_log_year) {
556
0
        os << std::setw(4) << local_tm.tm_year + 1900;
557
0
    }
558
0
    os << std::setw(2) << local_tm.tm_mon + 1
559
0
       << std::setw(2) << local_tm.tm_mday << ' '
560
0
       << std::setw(2) << local_tm.tm_hour << ':'
561
0
       << std::setw(2) << local_tm.tm_min << ':'
562
0
       << std::setw(2) << local_tm.tm_sec;
563
0
#if defined(OS_LINUX)
564
0
    os << '.' << std::setw(6) << tv.tv_usec;
565
0
#endif
566
0
    os << "\",";
567
0
    os.fill(prev_fill);
568
569
0
    if (FLAGS_log_pid) {
570
0
        os << "\"pid\":\"" << CurrentProcessId() << "\",";
571
0
    }
572
0
    os << "\"tid\":\"" << butil::PlatformThread::CurrentId() << "\",";
573
0
    if (FLAGS_log_hostname) {
574
0
        butil::StringPiece hostname(butil::my_hostname());
575
0
        if (hostname.ends_with(".baidu.com")) { // make it shorter
576
0
            hostname.remove_suffix(10);
577
0
        }
578
0
        os << "\"host\":\"" << hostname << "\",";
579
0
    }
580
0
    os << "\"C\":\"" << file << ':' << line;
581
0
    if (func && *func != '\0') {
582
0
        os << " " << func;
583
0
    }
584
0
    os << "\"";
585
0
}
586
587
0
void EscapeJson(std::ostream& os, const butil::StringPiece& s) {
588
0
    for (auto it = s.begin(); it != s.end(); it++) {
589
0
        auto c = *it;
590
0
        switch (c) {
591
0
        case '"': os << "\\\""; break;
592
0
        case '\\': os << "\\\\"; break;
593
0
        case '\b': os << "\\b"; break;
594
0
        case '\f': os << "\\f"; break;
595
0
        case '\n': os << "\\n"; break;
596
0
        case '\r': os << "\\r"; break;
597
0
        case '\t': os << "\\t"; break;
598
0
        default: os << c;
599
0
        }
600
0
    }
601
0
}
602
603
3.42k
inline void OutputLog(std::ostream& os, const butil::StringPiece& s) {
604
3.42k
    if (FLAGS_escape_log) {
605
0
        EscapeJson(os, s);
606
3.42k
    } else {
607
3.42k
        os.write(s.data(), s.length());
608
3.42k
    }
609
3.42k
}
610
611
void PrintLog(std::ostream& os, int severity, const char* file, int line,
612
3.42k
              const char* func, const butil::StringPiece& content) {
613
3.42k
    if (!FLAGS_log_as_json) {
614
3.42k
        PrintLogPrefix(os, severity, file, line, func);
615
3.42k
        OutputLog(os, content);
616
3.42k
    } else {
617
0
        os << '{';
618
0
        PrintLogPrefixAsJSON(os, severity, file, func, line);
619
0
        bool pair_quote = false;
620
0
        if (content.empty() || content[0] != '"') {
621
            // not a json, add a 'M' field
622
0
            os << ",\"M\":\"";
623
0
            pair_quote = true;
624
0
        } else {
625
0
            os << ',';
626
0
        }
627
0
        OutputLog(os, content);
628
0
        if (pair_quote) {
629
0
            os << '"';
630
0
        } else if (!content.empty() && content[content.size()-1] != '"') {
631
            // Controller may write `"M":"...` which misses the last quote
632
0
            os << '"';
633
0
        }
634
0
        os << '}';
635
0
    }
636
3.42k
}
637
638
void PrintLog(std::ostream& os,
639
              int severity, const char* file, int line,
640
0
              const butil::StringPiece& content) {
641
0
    PrintLog(os, severity, file, line, "", content);
642
0
}
643
644
// A log message handler that gets notified of every log message we process.
645
class DoublyBufferedLogSink : public butil::DoublyBufferedData<LogSink*> {
646
public:
647
1
    DoublyBufferedLogSink() {}
648
    static DoublyBufferedLogSink* GetInstance();
649
private:
650
friend struct DefaultSingletonTraits<DoublyBufferedLogSink>;
651
    DISALLOW_COPY_AND_ASSIGN(DoublyBufferedLogSink);
652
};
653
654
3.42k
DoublyBufferedLogSink* DoublyBufferedLogSink::GetInstance() {
655
3.42k
    return Singleton<DoublyBufferedLogSink,
656
3.42k
                     LeakySingletonTraits<DoublyBufferedLogSink> >::get();
657
3.42k
}
658
659
struct SetLogSinkFn {
660
    LogSink* new_sink;
661
    LogSink* old_sink;
662
663
0
    bool operator()(LogSink*& ptr) {
664
0
        old_sink = ptr;
665
0
        ptr = new_sink;
666
0
        return true;
667
0
    }
668
};
669
670
0
LogSink* SetLogSink(LogSink* sink) {
671
0
    SetLogSinkFn fn = { sink, NULL };
672
0
    CHECK(DoublyBufferedLogSink::GetInstance()->Modify(fn));
673
0
    return fn.old_sink;
674
0
}
675
676
// MSVC doesn't like complex extern templates and DLLs.
677
#if !defined(COMPILER_MSVC)
678
// Explicit instantiations for commonly used comparisons.
679
template std::string* MakeCheckOpString<int, int>(
680
    const int&, const int&, const char* names);
681
template std::string* MakeCheckOpString<unsigned long, unsigned long>(
682
    const unsigned long&, const unsigned long&, const char* names);
683
template std::string* MakeCheckOpString<unsigned long, unsigned int>(
684
    const unsigned long&, const unsigned int&, const char* names);
685
template std::string* MakeCheckOpString<unsigned int, unsigned long>(
686
    const unsigned int&, const unsigned long&, const char* names);
687
template std::string* MakeCheckOpString<std::string, std::string>(
688
    const std::string&, const std::string&, const char* name);
689
#endif
690
691
#if !defined(NDEBUG)
692
// Displays a message box to the user with the error message in it.
693
// Used for fatal messages, where we close the app simultaneously.
694
// This is for developers only; we don't use this in circumstances
695
// (like release builds) where users could see it, since users don't
696
// understand these messages anyway.
697
0
void DisplayDebugMessageInDialog(const std::string& str) {
698
0
    if (str.empty())
699
0
        return;
700
701
0
    if (!show_error_dialogs)
702
0
        return;
703
704
#if defined(OS_WIN)
705
    // For Windows programs, it's possible that the message loop is
706
    // messed up on a fatal error, and creating a MessageBox will cause
707
    // that message loop to be run. Instead, we try to spawn another
708
    // process that displays its command line. We look for "Debug
709
    // Message.exe" in the same directory as the application. If it
710
    // exists, we use it, otherwise, we use a regular message box.
711
    wchar_t prog_name[MAX_PATH];
712
    GetModuleFileNameW(NULL, prog_name, MAX_PATH);
713
    wchar_t* backslash = wcsrchr(prog_name, '\\');
714
    if (backslash)
715
        backslash[1] = 0;
716
    wcscat_s(prog_name, MAX_PATH, L"debug_message.exe");
717
718
    std::wstring cmdline = butil::UTF8ToWide(str);
719
    if (cmdline.empty())
720
        return;
721
722
    STARTUPINFO startup_info;
723
    memset(&startup_info, 0, sizeof(startup_info));
724
    startup_info.cb = sizeof(startup_info);
725
726
    PROCESS_INFORMATION process_info;
727
    if (CreateProcessW(prog_name, &cmdline[0], NULL, NULL, false, 0, NULL,
728
                       NULL, &startup_info, &process_info)) {
729
        WaitForSingleObject(process_info.hProcess, INFINITE);
730
        CloseHandle(process_info.hThread);
731
        CloseHandle(process_info.hProcess);
732
    } else {
733
        // debug process broken, let's just do a message box
734
        MessageBoxW(NULL, &cmdline[0], L"Fatal error",
735
                    MB_OK | MB_ICONHAND | MB_TOPMOST);
736
    }
737
#else
738
    // We intentionally don't implement a dialog on other platforms.
739
    // You can just look at stderr.
740
0
#endif
741
0
}
742
#endif  // !defined(NDEBUG)
743
744
745
bool StringSink::OnLogMessage(int severity, const char* file, int line,
746
0
                              const butil::StringPiece& content) {
747
0
    return OnLogMessage(severity, file, line, "", content);
748
0
}
749
750
bool StringSink::OnLogMessage(int severity, const char* file,
751
                              int line, const char* func,
752
0
                              const butil::StringPiece& content) {
753
0
    std::ostringstream os;
754
0
    PrintLog(os, severity, file, line, func, content);
755
0
    const std::string msg = os.str();
756
0
    {
757
0
        butil::AutoLock lock_guard(_lock);
758
0
        append(msg);
759
0
    }
760
0
    return true;
761
0
}
762
763
0
CharArrayStreamBuf::~CharArrayStreamBuf() {
764
0
    free(_data);
765
0
}
766
767
1
int CharArrayStreamBuf::overflow(int ch) {
768
1
    if (ch == std::streambuf::traits_type::eof()) {
769
0
        return ch;
770
0
    }
771
1
    size_t new_size = std::max(_size * 3 / 2, (size_t)64);
772
1
    char* new_data = (char*)malloc(new_size);
773
1
    if (BAIDU_UNLIKELY(new_data == NULL)) {
774
0
        setp(NULL, NULL);
775
0
        return std::streambuf::traits_type::eof();
776
0
    }
777
1
    memcpy(new_data, _data, _size);
778
1
    free(_data);
779
1
    _data = new_data;
780
1
    const size_t old_size = _size;
781
1
    _size = new_size;
782
1
    setp(_data, _data + new_size);
783
1
    pbump(old_size);
784
    // if size == 1, this function will call overflow again.
785
1
    return sputc(ch);
786
1
}
787
788
0
int CharArrayStreamBuf::sync() {
789
    // data are already there.
790
0
    return 0;
791
0
}
792
793
3.42k
void CharArrayStreamBuf::reset() {
794
3.42k
    setp(_data, _data + _size);
795
3.42k
}
796
797
LogStream& LogStream::SetPosition(const LogChar* file, int line,
798
0
                                  LogSeverity severity) {
799
0
    _file = file;
800
0
    _line = line;
801
0
    _severity = severity;
802
0
    return *this;
803
0
}
804
805
LogStream& LogStream::SetPosition(const LogChar* file, int line,
806
                                  const LogChar* func,
807
3.42k
                                  LogSeverity severity) {
808
3.42k
    _file = file;
809
3.42k
    _line = line;
810
3.42k
    _func = func;
811
3.42k
    _severity = severity;
812
3.42k
    return *this;
813
3.42k
}
814
815
#if defined(__GNUC__)
816
static bthread_key_t stream_bkey;
817
static pthread_key_t stream_pkey;
818
static pthread_once_t create_stream_key_once = PTHREAD_ONCE_INIT;
819
3.42k
inline bool is_bthread_linked() { return bthread_key_create != NULL; }
820
0
static void destroy_tls_streams(void* data) {
821
0
    if (data == NULL) {
822
0
        return;
823
0
    }
824
0
    LogStream** a = (LogStream**)data;
825
0
    for (int i = 0; i <= LOG_NUM_SEVERITIES; ++i) {
826
0
        delete a[i];
827
0
    }
828
0
    delete[] a;
829
0
}
830
1
static void create_stream_key_or_die() {
831
1
    if (is_bthread_linked()) {
832
1
        int rc = bthread_key_create(&stream_bkey, destroy_tls_streams);
833
1
        if (rc) {
834
0
            fprintf(stderr, "Fail to bthread_key_create");
835
0
            exit(1);
836
0
        }
837
1
    } else {
838
0
        int rc = pthread_key_create(&stream_pkey, destroy_tls_streams);
839
0
        if (rc) {
840
0
            fprintf(stderr, "Fail to pthread_key_create");
841
0
            exit(1);
842
0
        }
843
0
    }
844
1
}
845
3.42k
static LogStream** get_tls_stream_array() {
846
3.42k
    pthread_once(&create_stream_key_once, create_stream_key_or_die);
847
3.42k
    if (is_bthread_linked()) {
848
3.42k
        return (LogStream**)bthread_getspecific(stream_bkey);
849
3.42k
    } else {
850
0
        return (LogStream**)pthread_getspecific(stream_pkey);
851
0
    }
852
3.42k
}
853
854
3.42k
static LogStream** get_or_new_tls_stream_array() {
855
3.42k
    LogStream** a = get_tls_stream_array();
856
3.42k
    if (a == NULL) {
857
1
        a = new LogStream*[LOG_NUM_SEVERITIES + 1];
858
1
        memset(a, 0, sizeof(LogStream*) * (LOG_NUM_SEVERITIES + 1));
859
1
        if (is_bthread_linked()) {
860
1
            bthread_setspecific(stream_bkey, a);
861
1
        } else {
862
0
            pthread_setspecific(stream_pkey, a);
863
0
        }
864
1
    }
865
3.42k
    return a;
866
3.42k
}
867
868
inline LogStream* CreateLogStream(const LogChar* file,
869
                                  int line,
870
                                  const LogChar* func,
871
3.42k
                                  LogSeverity severity) {
872
3.42k
    int slot = 0;
873
3.42k
    if (severity >= 0) {
874
3.42k
        DCHECK_LT(severity, LOG_NUM_SEVERITIES);
875
3.42k
        slot = severity + 1;
876
3.42k
    } // else vlog
877
3.42k
    LogStream** stream_array = get_or_new_tls_stream_array();
878
3.42k
    LogStream* stream = stream_array[slot];
879
3.42k
    if (stream == NULL) {
880
1
        stream = new LogStream;
881
1
        stream_array[slot] = stream;
882
1
    }
883
3.42k
    if (stream->empty()) {
884
3.42k
        stream->SetPosition(file, line, func, severity);
885
3.42k
    }
886
3.42k
    return stream;
887
3.42k
}
888
889
inline LogStream* CreateLogStream(const LogChar* file,
890
                                  int line,
891
0
                                  LogSeverity severity) {
892
0
    return CreateLogStream(file, line, "", severity);
893
0
}
894
895
3.42k
inline void DestroyLogStream(LogStream* stream) {
896
3.42k
    if (stream != NULL) {
897
3.42k
        stream->Flush();
898
3.42k
    }
899
3.42k
}
900
901
#else
902
903
inline LogStream* CreateLogStream(const LogChar* file, int line,
904
                                  LogSeverity severity) {
905
    return CreateLogStream(file, line, "", severity);
906
}
907
908
909
inline LogStream* CreateLogStream(const LogChar* file, int line,
910
                                  const LogChar* func,
911
                                  LogSeverity severity) {
912
    LogStream* stream = new LogStream;
913
    stream->SetPosition(file, line, func, severity);
914
    return stream;
915
}
916
917
inline void DestroyLogStream(LogStream* stream) {
918
    delete stream;
919
}
920
921
#endif  // __GNUC__
922
923
class DefaultLogSink : public LogSink {
924
public:
925
3.42k
    static DefaultLogSink* GetInstance() {
926
3.42k
        return Singleton<DefaultLogSink,
927
3.42k
                         LeakySingletonTraits<DefaultLogSink> >::get();
928
3.42k
    }
929
930
    bool OnLogMessage(int severity, const char* file, int line,
931
3.42k
                      const butil::StringPiece& content) override {
932
3.42k
        return OnLogMessage(severity, file, line, "", content);
933
3.42k
    }
934
935
    bool OnLogMessage(int severity, const char* file,
936
                      int line, const char* func,
937
3.42k
                      const butil::StringPiece& content) override {
938
        // There's a copy here to concatenate prefix and content. Since
939
        // DefaultLogSink is hardly used right now, the copy is irrelevant.
940
        // A LogSink focused on performance should also be able to handle
941
        // non-continuous inputs which is a must to maximize performance.
942
3.42k
        std::ostringstream os;
943
3.42k
        PrintLog(os, severity, file, line, func, content);
944
3.42k
        os << '\n';
945
3.42k
        std::string log = os.str();
946
        
947
3.42k
        if ((logging_destination & LOG_TO_SYSTEM_DEBUG_LOG) != 0) {
948
3.42k
            fwrite(log.data(), log.size(), 1, stderr);
949
3.42k
            fflush(stderr);
950
3.42k
        } else if (severity >= kAlwaysPrintErrorLevel) {
951
            // When we're only outputting to a log file, above a certain log level, we
952
            // should still output to stderr so that we can better detect and diagnose
953
            // problems with unit tests, especially on the buildbots.
954
0
            fwrite(log.data(), log.size(), 1, stderr);
955
0
            fflush(stderr);
956
0
        }
957
958
        // write to log file
959
3.42k
        if ((logging_destination & LOG_TO_FILE) != 0) {
960
            // We can have multiple threads and/or processes, so try to prevent them
961
            // from clobbering each other's writes.
962
            // If the client app did not call InitLogging, and the lock has not
963
            // been created do it now. We do this on demand, but if two threads try
964
            // to do this at the same time, there will be a race condition to create
965
            // the lock. This is why InitLogging should be called from the main
966
            // thread at the beginning of execution.
967
0
            LoggingLock::Init(LOCK_LOG_FILE, NULL);
968
0
            LoggingLock logging_lock;
969
0
            if (InitializeLogFileHandle()) {
970
#if defined(OS_WIN)
971
                SetFilePointer(log_file, 0, 0, SEEK_END);
972
                DWORD num_written;
973
                WriteFile(log_file,
974
                          static_cast<const void*>(log.data()),
975
                          static_cast<DWORD>(log.size()),
976
                          &num_written,
977
                          NULL);
978
#else
979
0
                fwrite(log.data(), log.size(), 1, log_file);
980
0
                fflush(log_file);
981
0
#endif
982
0
            }
983
0
        }
984
3.42k
        return true;
985
3.42k
    }
986
private:
987
1
    DefaultLogSink() {}
988
0
    ~DefaultLogSink() {}
989
friend struct DefaultSingletonTraits<DefaultLogSink>;
990
};
991
992
3.42k
void LogStream::FlushWithoutReset() {
993
3.42k
    if (empty()) {
994
        // Nothing to flush.
995
0
        return;
996
0
    }
997
998
3.42k
#if !defined(OS_NACL) && !defined(__UCLIBC__)
999
3.42k
    if (FLAGS_print_stack_on_check && _is_check && _severity == BLOG_FATAL) {
1000
        // Include a stack trace on a fatal.
1001
0
        butil::debug::StackTrace trace;
1002
0
        size_t count = 0;
1003
0
        const void* const* addrs = trace.Addresses(&count);
1004
1005
0
        *this << std::endl;  // Newline to separate from log message.
1006
0
        if (count > 3) {
1007
            // Remove top 3 frames which are useless to users.
1008
            // #2 may be ~LogStream
1009
            //   #0 0x00000059ccae butil::debug::StackTrace::StackTrace()
1010
            //   #1 0x0000005947c7 logging::LogStream::FlushWithoutReset()
1011
            //   #2 0x000000594b88 logging::LogMessage::~LogMessage()
1012
0
            butil::debug::StackTrace trace_stripped(addrs + 3, count - 3);
1013
0
            trace_stripped.OutputToStream(this);
1014
0
        } else {
1015
0
            trace.OutputToStream(this);
1016
0
        }
1017
0
    }
1018
3.42k
#endif
1019
    // End the data with zero because sink is likely to assume this.
1020
3.42k
    *this << std::ends;
1021
    // Move back one step because we don't want to count the zero.
1022
3.42k
    pbump(-1); 
1023
1024
    // Give any logsink first dibs on the message.
1025
#ifdef BAIDU_INTERNAL
1026
    // If the logsink fails and it's not comlog, try comlog. stderr on last try.
1027
    bool tried_comlog = false;
1028
#endif
1029
3.42k
    bool tried_default = false;
1030
3.42k
    {
1031
3.42k
        DoublyBufferedLogSink::ScopedPtr ptr;
1032
3.42k
        if (DoublyBufferedLogSink::GetInstance()->Read(&ptr) == 0 &&
1033
3.42k
            (*ptr) != NULL) {
1034
0
            bool result = false;
1035
0
            if (FLAGS_log_func_name) {
1036
0
                result = (*ptr)->OnLogMessage(_severity, _file, _line,
1037
0
                                              _func, content());
1038
0
            } else {
1039
0
                result = (*ptr)->OnLogMessage(_severity, _file,
1040
0
                                              _line, content());
1041
0
            }
1042
0
            if (result) {
1043
0
                goto FINISH_LOGGING;
1044
0
            }
1045
#ifdef BAIDU_INTERNAL
1046
            tried_comlog = (*ptr == ComlogSink::GetInstance());
1047
#endif
1048
0
            tried_default = (*ptr == DefaultLogSink::GetInstance());
1049
0
        }
1050
3.42k
    }
1051
1052
#ifdef BAIDU_INTERNAL
1053
    if (!tried_comlog) {
1054
        if (ComlogSink::GetInstance()->OnLogMessage(
1055
                _severity, _file, _line, _func, content())) {
1056
            goto FINISH_LOGGING;
1057
        }
1058
    }
1059
#endif
1060
3.42k
    if (!tried_default) {
1061
3.42k
        if (FLAGS_log_func_name) {
1062
0
            DefaultLogSink::GetInstance()->OnLogMessage(
1063
0
                _severity, _file, _line, _func, content());
1064
3.42k
        } else {
1065
3.42k
            DefaultLogSink::GetInstance()->OnLogMessage(
1066
3.42k
                _severity, _file, _line, content());
1067
3.42k
        }
1068
3.42k
    }
1069
1070
3.42k
FINISH_LOGGING:
1071
3.42k
    if (FLAGS_crash_on_fatal_log && _severity == BLOG_FATAL) {
1072
        // Ensure the first characters of the string are on the stack so they
1073
        // are contained in minidumps for diagnostic purposes.
1074
0
        butil::StringPiece str = content();
1075
0
        char str_stack[1024];
1076
0
        str.copy(str_stack, arraysize(str_stack));
1077
0
        butil::debug::Alias(str_stack);
1078
1079
0
        if (log_assert_handler) {
1080
            // Make a copy of the string for the handler out of paranoia.
1081
0
            log_assert_handler(str.as_string());
1082
0
        } else {
1083
            // Don't use the string with the newline, get a fresh version to send to
1084
            // the debug message process. We also don't display assertions to the
1085
            // user in release mode. The enduser can't do anything with this
1086
            // information, and displaying message boxes when the application is
1087
            // hosed can cause additional problems.
1088
0
#ifndef NDEBUG
1089
0
            DisplayDebugMessageInDialog(str.as_string());
1090
0
#endif
1091
            // Crash the process to generate a dump.
1092
0
            butil::debug::BreakDebugger();
1093
0
        }
1094
0
    }
1095
3.42k
}
1096
1097
LogMessage::LogMessage(const char* file, int line, LogSeverity severity)
1098
0
    : LogMessage(file, line, "", severity) {}
1099
1100
LogMessage::LogMessage(const char* file, int line,
1101
3.42k
                       const char* func, LogSeverity severity) {
1102
3.42k
    _stream = CreateLogStream(file, line, func, severity);
1103
3.42k
}
1104
1105
LogMessage::LogMessage(const char* file, int line, std::string* result)
1106
0
    : LogMessage(file, line, "", result) {}
1107
1108
LogMessage::LogMessage(const char* file, int line,
1109
0
                       const char* func, std::string* result) {
1110
0
    _stream = CreateLogStream(file, line, func, BLOG_FATAL);
1111
0
    *_stream << "Check failed: " << *result;
1112
0
    delete result;
1113
0
}
1114
1115
LogMessage::LogMessage(const char* file, int line, LogSeverity severity,
1116
                       std::string* result)
1117
0
   : LogMessage(file, line, "", severity, result) {}
1118
1119
LogMessage::LogMessage(const char* file, int line, const char* func,
1120
0
                       LogSeverity severity, std::string* result) {
1121
0
    _stream = CreateLogStream(file, line, func, severity);
1122
0
    *_stream << "Check failed: " << *result;
1123
0
    delete result;
1124
0
}
1125
1126
3.42k
LogMessage::~LogMessage() {
1127
3.42k
    DestroyLogStream(_stream);
1128
3.42k
}
1129
1130
#if defined(OS_WIN)
1131
// This has already been defined in the header, but defining it again as DWORD
1132
// ensures that the type used in the header is equivalent to DWORD. If not,
1133
// the redefinition is a compile error.
1134
typedef DWORD SystemErrorCode;
1135
#endif
1136
1137
3.42k
SystemErrorCode GetLastSystemErrorCode() {
1138
#if defined(OS_WIN)
1139
    return ::GetLastError();
1140
#elif defined(OS_POSIX)
1141
3.42k
    return errno;
1142
#else
1143
#error Not implemented
1144
#endif
1145
3.42k
}
1146
1147
3.42k
void SetLastSystemErrorCode(SystemErrorCode err) {
1148
#if defined(OS_WIN)
1149
    ::SetLastError(err);
1150
#elif defined(OS_POSIX)
1151
    errno = err;
1152
#else
1153
#error Not implemented
1154
#endif
1155
3.42k
}
1156
1157
#if defined(OS_WIN)
1158
BUTIL_EXPORT std::string SystemErrorCodeToString(SystemErrorCode error_code) {
1159
    const int error_message_buffer_size = 256;
1160
    char msgbuf[error_message_buffer_size];
1161
    DWORD flags = FORMAT_MESSAGE_FROM_SYSTEM | FORMAT_MESSAGE_IGNORE_INSERTS;
1162
    DWORD len = FormatMessageA(flags, NULL, error_code, 0, msgbuf,
1163
                               arraysize(msgbuf), NULL);
1164
    if (len) {
1165
        // Messages returned by system end with line breaks.
1166
        return butil::CollapseWhitespaceASCII(msgbuf, true) +
1167
            butil::StringPrintf(" (0x%X)", error_code);
1168
    }
1169
    return butil::StringPrintf("Error (0x%X) while retrieving error. (0x%X)",
1170
                              GetLastError(), error_code);
1171
}
1172
#elif defined(OS_POSIX)
1173
0
BUTIL_EXPORT std::string SystemErrorCodeToString(SystemErrorCode error_code) {
1174
0
    return berror(error_code);
1175
0
}
1176
#else
1177
#error Not implemented
1178
#endif
1179
1180
1181
#if defined(OS_WIN)
1182
Win32ErrorLogMessage::Win32ErrorLogMessage(const char* file,
1183
                                           int line,
1184
                                           LogSeverity severity,
1185
                                           SystemErrorCode err)
1186
   : Win32ErrorLogMessage(file, line, "", severity, err) {
1187
}
1188
1189
Win32ErrorLogMessage::Win32ErrorLogMessage(const char* file,
1190
                                           int line,
1191
                                           const char* func,
1192
                                           LogSeverity severity,
1193
                                           SystemErrorCode err)
1194
    : err_(err)
1195
    , log_message_(file, line, func, severity) {
1196
}
1197
1198
Win32ErrorLogMessage::~Win32ErrorLogMessage() {
1199
    stream() << ": " << SystemErrorCodeToString(err_);
1200
    // We're about to crash (CHECK). Put |err_| on the stack (by placing it in a
1201
    // field) and use Alias in hopes that it makes it into crash dumps.
1202
    DWORD last_error = err_;
1203
    butil::debug::Alias(&last_error);
1204
}
1205
#elif defined(OS_POSIX)
1206
ErrnoLogMessage::ErrnoLogMessage(const char* file,
1207
                                 int line,
1208
                                 LogSeverity severity,
1209
                                 SystemErrorCode err)
1210
0
    : ErrnoLogMessage(file, line, "", severity, err) {}
1211
1212
ErrnoLogMessage::ErrnoLogMessage(const char* file,
1213
                                 int line,
1214
                                 const char* func,
1215
                                 LogSeverity severity,
1216
                                 SystemErrorCode err)
1217
    : err_(err)
1218
0
    , log_message_(file, line, func, severity) {}
1219
1220
0
ErrnoLogMessage::~ErrnoLogMessage() {
1221
0
    stream() << ": " << SystemErrorCodeToString(err_);
1222
0
}
1223
#endif  // OS_WIN
1224
1225
0
void CloseLogFile() {
1226
0
    LoggingLock logging_lock;
1227
0
    CloseLogFileUnlocked();
1228
0
}
1229
1230
0
void RawLog(int level, const char* message) {
1231
0
    if (level >= FLAGS_minloglevel) {
1232
0
        size_t bytes_written = 0;
1233
0
        const size_t message_len = strlen(message);
1234
0
        int rv;
1235
0
        while (bytes_written < message_len) {
1236
0
            rv = HANDLE_EINTR(
1237
0
                write(STDERR_FILENO, message + bytes_written,
1238
0
                      message_len - bytes_written));
1239
0
            if (rv < 0) {
1240
                // Give up, nothing we can do now.
1241
0
                break;
1242
0
            }
1243
0
            bytes_written += rv;
1244
0
        }
1245
1246
0
        if (message_len > 0 && message[message_len - 1] != '\n') {
1247
0
            do {
1248
0
                rv = HANDLE_EINTR(write(STDERR_FILENO, "\n", 1));
1249
0
                if (rv < 0) {
1250
                    // Give up, nothing we can do now.
1251
0
                    break;
1252
0
                }
1253
0
            } while (rv != 1);
1254
0
        }
1255
0
    }
1256
1257
0
    if (FLAGS_crash_on_fatal_log && level == BLOG_FATAL)
1258
0
        butil::debug::BreakDebugger();
1259
0
}
1260
1261
// This was defined at the beginning of this file.
1262
#undef write
1263
1264
#if defined(OS_WIN)
1265
std::wstring GetLogFileFullPath() {
1266
    if (log_file_name)
1267
        return *log_file_name;
1268
    return std::wstring();
1269
}
1270
#endif
1271
1272
1273
// ----------- VLOG stuff -----------------
1274
struct VLogSite;
1275
struct VModuleList;
1276
1277
extern const int VLOG_UNINITIALIZED = std::numeric_limits<int>::max();
1278
1279
static pthread_mutex_t vlog_site_list_mutex = PTHREAD_MUTEX_INITIALIZER;
1280
static VLogSite* vlog_site_list = NULL;
1281
static VModuleList* vmodule_list = NULL;
1282
1283
static pthread_mutex_t reset_vmodule_and_v_mutex = PTHREAD_MUTEX_INITIALIZER;
1284
1285
static const int64_t DELAY_DELETION_SEC = 10;
1286
static std::deque<std::pair<VModuleList*, int64_t> >*
1287
deleting_vmodule_list = NULL;
1288
1289
struct VLogSite {
1290
    VLogSite(const char* filename, int required_v, int line_no)
1291
1
        : _next(0), _v(0), _required_v(required_v), _line_no(line_no) {
1292
        // Remove dirname/extname.
1293
1
        butil::StringPiece s(filename);
1294
1
        size_t pos = s.find_last_of("./");
1295
1
        if (pos != butil::StringPiece::npos) {
1296
1
            if (s[pos] == '.') {
1297
1
                s.remove_suffix(s.size() - pos);
1298
1
                _full_module.assign(s.data(), s.size());
1299
1
                size_t pos2 = s.find_last_of('/');
1300
1
                if (pos2 != butil::StringPiece::npos) {
1301
1
                    s.remove_prefix(pos2 + 1);
1302
1
                }
1303
1
            } else {
1304
0
                _full_module.assign(s.data(), s.size());
1305
0
                s.remove_prefix(pos + 1);
1306
0
            }
1307
1
        } // else keep _full_module empty when it equals _module
1308
1
        _module.assign(s.data(), s.size());
1309
1
        std::transform(_module.begin(), _module.end(),
1310
1
                       _module.begin(), ::tolower);
1311
1
        if (!_full_module.empty()) {
1312
1
            std::transform(_full_module.begin(), _full_module.end(),
1313
1
                           _full_module.begin(), ::tolower);
1314
1
        }
1315
1
    }
1316
1317
    // The consume/release fence makes the iteration outside lock see
1318
    // newly added VLogSite correctly.
1319
0
    VLogSite* next() { return (VLogSite*)butil::subtle::Acquire_Load(&_next); }
1320
    const VLogSite* next() const
1321
0
    { return (VLogSite*)butil::subtle::Acquire_Load(&_next); }
1322
    void set_next(VLogSite* next)
1323
1
    { butil::subtle::Release_Store(&_next, (butil::subtle::AtomicWord)next); }
1324
1325
0
    int v() const { return _v; }
1326
3
    int& v() { return _v; }
1327
1328
0
    int required_v() const { return  _required_v; }
1329
0
    int line_no() const { return _line_no; }
1330
1331
0
    const std::string& module() const { return _module; }
1332
0
    const std::string& full_module() const { return _full_module; }
1333
    
1334
private:
1335
    // Next site in the list. NULL means no next.
1336
    butil::subtle::AtomicWord _next;
1337
1338
    // --vmodule > --v
1339
    int _v;
1340
    
1341
    // vlog is on iff _v >= _required_v
1342
    int _required_v;
1343
1344
    // line nubmer of the vlog.
1345
    int _line_no;
1346
    
1347
    // Lowered, dirname & extname removed.
1348
    std::string _module;
1349
    // Lowered, extname removed. Empty when it equals to _module.
1350
    std::string _full_module;
1351
};
1352
1353
// Written by Jack Handy
1354
// <A href="mailto:jakkhandy@hotmail.com">jakkhandy@hotmail.com</A>
1355
0
bool wildcmp(const char* wild, const char* str) {
1356
0
    const char* cp = NULL;
1357
0
    const char* mp = NULL;
1358
1359
0
    while (*str && *wild != '*') {
1360
0
        if (*wild != *str && *wild != '?') {
1361
0
            return false;
1362
0
        }
1363
0
        ++wild;
1364
0
        ++str;
1365
0
    }
1366
1367
0
    while (*str) {
1368
0
        if (*wild == '*') {
1369
0
            if (!*++wild) {
1370
0
                return true;
1371
0
            }
1372
0
            mp = wild;
1373
0
            cp = str+1;
1374
0
        } else if (*wild == *str || *wild == '?') {
1375
0
            ++wild;
1376
0
            ++str;
1377
0
        } else {
1378
0
            wild = mp;
1379
0
            str = cp++;
1380
0
        }
1381
0
    }
1382
1383
0
    while (*wild == '*') {
1384
0
        ++wild;
1385
0
    }
1386
0
    return !*wild;
1387
0
}
1388
1389
struct VModuleList {
1390
0
    VModuleList() {}
1391
1392
0
    int init(const char* vmodules) {
1393
0
        _exact_names.clear();
1394
0
        _wild_names.clear();
1395
                           
1396
0
        for (butil::StringSplitter sp(vmodules, ','); sp; ++sp) {
1397
0
            int verbose_level = std::numeric_limits<int>::max();
1398
0
            size_t off = 0;
1399
0
            for (; off < sp.length() && sp.field()[off] != '='; ++off) {}
1400
0
            if (off + 1 < sp.length()) {
1401
0
                verbose_level = strtol(sp.field() + off + 1, NULL, 10);
1402
                
1403
0
            }
1404
0
            const char* name_begin = sp.field();
1405
0
            const char* name_end = sp.field() + off - 1;
1406
0
            for (; isspace(*name_begin) && name_begin < sp.field() + off;
1407
0
                 ++name_begin) {}
1408
0
            for (; isspace(*name_end) && name_end >= sp.field(); --name_end) {}
1409
            
1410
0
            if (name_begin > name_end) {  // only has spaces
1411
0
                continue;
1412
0
            }
1413
0
            std::string name(name_begin, name_end - name_begin + 1);
1414
0
            std::transform(name.begin(), name.end(), name.begin(), ::tolower);
1415
0
            if (name.find_first_of("*?") == std::string::npos) {
1416
0
                _exact_names[name] = verbose_level;
1417
0
            } else {
1418
0
                _wild_names.emplace_back(name, verbose_level);
1419
0
            }
1420
0
        }
1421
        // Reverse _wild_names so that latter wild cards override former ones.
1422
0
        if (!_wild_names.empty()) {
1423
0
            std::reverse(_wild_names.begin(), _wild_names.end());
1424
0
        }
1425
0
        return 0;
1426
0
    }
1427
1428
    bool find_verbose_level(const std::string& module,
1429
0
                            const std::string& full_module, int* v) const {
1430
0
        if (!_exact_names.empty()) {
1431
0
            std::map<std::string, int>::const_iterator
1432
0
                it = _exact_names.find(module);
1433
0
            if (it != _exact_names.end()) {
1434
0
                *v = it->second;
1435
0
                return true;
1436
0
            }
1437
0
            if (!full_module.empty()) {
1438
0
                it = _exact_names.find(full_module);
1439
0
                if (it != _exact_names.end()) {
1440
0
                    *v = it->second;
1441
0
                    return true;
1442
0
                }
1443
0
            }
1444
0
        }
1445
1446
0
        for (size_t i = 0; i < _wild_names.size(); ++i) {
1447
0
            if (wildcmp(_wild_names[i].first.c_str(), module.c_str())) {
1448
0
                *v = _wild_names[i].second;
1449
0
                return true;
1450
0
            }
1451
0
            if (!full_module.empty() &&
1452
0
                wildcmp(_wild_names[i].first.c_str(), full_module.c_str())) {
1453
0
                *v = _wild_names[i].second;
1454
0
                return true;
1455
0
            }
1456
0
        }
1457
0
        return false;
1458
0
    }
1459
1460
0
    void print(std::ostream& os) const {
1461
0
        os << "exact:";
1462
0
        for (std::map<std::string, int>::const_iterator
1463
0
                 it = _exact_names.begin(); it != _exact_names.end(); ++it) {
1464
0
            os << ' ' << it->first << '=' << it->second;
1465
0
        }
1466
0
        os << ", wild:";
1467
0
        for (size_t i = 0; i < _wild_names.size(); ++i) {
1468
0
            os << ' ' << _wild_names[i].first << '=' << _wild_names[i].second;
1469
0
        }
1470
0
    }
1471
1472
private:
1473
    std::map<std::string, int> _exact_names;
1474
    std::vector<std::pair<std::string, int> > _wild_names;
1475
};
1476
1477
// [ The idea ] 
1478
// Each callsite creates a VLogSite and inserts the site into singly-linked
1479
// vlog_site_list. To keep the critical area small, we use optimistic
1480
// locking : Assign local site w/o locking, then insert the site into
1481
// global list w/ locking, if local_module_list != global_vmodule_list or
1482
// local_default_v != FLAGS_v, repeat the assigment.
1483
// An important property of vlog_site_list is that: It does not remove sites.
1484
// When we need to iterate the list, we don't have to hold the lock. What we
1485
// do is to get the head of the list inside lock and iterate the list w/o
1486
// lock. If new sites is inserted during the iteration, it should see and
1487
// use the updated vmodule_list and FLAGS_v, nothing will be missed.
1488
1489
static int vlog_site_list_add(VLogSite* site,
1490
                              VModuleList** expected_module_list,
1491
1
                              int* expected_default_v) {
1492
1
    BAIDU_SCOPED_LOCK(vlog_site_list_mutex);
1493
1
    if (vmodule_list != *expected_module_list) {
1494
0
        *expected_module_list = vmodule_list;
1495
0
        return -1;
1496
0
    }
1497
1
    if (*expected_default_v != FLAGS_v) {
1498
0
        *expected_default_v = FLAGS_v;
1499
0
        return -1;
1500
0
    }
1501
1
    site->set_next(vlog_site_list);
1502
1
    vlog_site_list = site;
1503
1
    return 0;
1504
1
}
1505
1506
bool add_vlog_site(const int** v, const char* filename, int line_no,
1507
1
                   int required_v) {
1508
1
    VLogSite* site = new (std::nothrow) VLogSite(filename, required_v, line_no);
1509
1
    if (site == NULL) {
1510
0
        return false;
1511
0
    }
1512
1
    VModuleList* module_list = vmodule_list;
1513
1
    int default_v = FLAGS_v;
1514
1
    do {
1515
1
        site->v() = default_v;
1516
1
        if (module_list) {
1517
0
            module_list->find_verbose_level(
1518
0
                site->module(), site->full_module(), &site->v());
1519
0
        }
1520
1
    } while (vlog_site_list_add(site, &module_list, &default_v) != 0);
1521
1
    *v = &site->v();
1522
1
    return site->v() >= required_v;
1523
1
}
1524
1525
0
void print_vlog_sites(VLogSitePrinter* printer) {
1526
0
    VLogSite* head = NULL;
1527
0
    {
1528
0
        BAIDU_SCOPED_LOCK(vlog_site_list_mutex);
1529
0
        head = vlog_site_list;
1530
0
    }
1531
0
    VLogSitePrinter::Site site;
1532
0
    for (const VLogSite* p = head; p; p = p->next()) {
1533
0
        site.current_verbose_level = p->v();
1534
0
        site.required_verbose_level = p->required_v();
1535
0
        site.line_no = p->line_no();
1536
0
        site.full_module = p->full_module();
1537
0
        printer->print(site);
1538
0
    }
1539
0
}
1540
1541
// [Thread-safe] Reset FLAGS_vmodule.
1542
0
static int on_reset_vmodule(const char* vmodule) {
1543
    // resetting must be serialized.
1544
0
    BAIDU_SCOPED_LOCK(reset_vmodule_and_v_mutex);
1545
    
1546
0
    VModuleList* module_list = new (std::nothrow) VModuleList;
1547
0
    if (NULL == module_list) {
1548
0
        LOG(FATAL) << "Fail to new VModuleList";
1549
0
        return -1;
1550
0
    }
1551
0
    if (module_list->init(vmodule) != 0) {
1552
0
        delete module_list;
1553
0
        LOG(FATAL) << "Fail to init VModuleList";
1554
0
        return -1;
1555
0
    }
1556
    
1557
0
    VModuleList* old_module_list = NULL;
1558
0
    VLogSite* old_vlog_site_list = NULL;
1559
0
    {
1560
0
        {
1561
0
            BAIDU_SCOPED_LOCK(vlog_site_list_mutex);
1562
0
            old_module_list = vmodule_list;
1563
0
            vmodule_list = module_list;
1564
0
            old_vlog_site_list = vlog_site_list;
1565
0
        }
1566
0
        for (VLogSite* p = old_vlog_site_list; p; p = p->next()) {
1567
0
            p->v() = FLAGS_v;
1568
0
            module_list->find_verbose_level(
1569
0
                p->module(), p->full_module(), &p->v());
1570
0
        }
1571
0
    }
1572
    
1573
0
    if (old_module_list) {
1574
        //delay the deletion.
1575
0
        if (NULL == deleting_vmodule_list) {
1576
0
            deleting_vmodule_list =
1577
0
                new std::deque<std::pair<VModuleList*, int64_t> >;
1578
0
        }
1579
0
        deleting_vmodule_list->push_back(
1580
0
            std::make_pair(old_module_list,
1581
0
                           butil::gettimeofday_us() + DELAY_DELETION_SEC * 1000000L));
1582
0
        while (!deleting_vmodule_list->empty() &&
1583
0
               deleting_vmodule_list->front().second <= butil::gettimeofday_us()) {
1584
0
            delete deleting_vmodule_list->front().first;
1585
0
            deleting_vmodule_list->pop_front();
1586
0
        }
1587
0
    }
1588
0
    return 0;
1589
0
}
1590
1591
0
static bool validate_vmodule(const char*, const std::string& vmodule) {
1592
0
    return on_reset_vmodule(vmodule.c_str()) == 0;
1593
0
}
1594
1595
const bool ALLOW_UNUSED validate_vmodule_dummy = GFLAGS_NS::RegisterFlagValidator(
1596
    &FLAGS_vmodule, &validate_vmodule);
1597
1598
// [Thread-safe] Reset FLAGS_v.
1599
0
static void on_reset_verbose(int default_v) {
1600
0
    VModuleList* cur_module_list = NULL;
1601
0
    VLogSite* cur_vlog_site_list = NULL;
1602
0
    {
1603
        // resetting must be serialized.
1604
0
        BAIDU_SCOPED_LOCK(reset_vmodule_and_v_mutex);
1605
0
        {
1606
0
            BAIDU_SCOPED_LOCK(vlog_site_list_mutex);
1607
0
            cur_module_list = vmodule_list;
1608
0
            cur_vlog_site_list = vlog_site_list;
1609
0
        }
1610
0
        for (VLogSite* p = cur_vlog_site_list; p; p = p->next()) {
1611
0
            p->v() = default_v;
1612
0
            if (cur_module_list) {
1613
0
                cur_module_list->find_verbose_level(
1614
0
                    p->module(), p->full_module(), &p->v());
1615
0
            }
1616
0
        }
1617
0
    }
1618
0
}
1619
1620
0
static bool validate_v(const char*, int32_t v) {
1621
0
    on_reset_verbose(v);
1622
0
    return true;
1623
0
}
1624
1625
const bool ALLOW_UNUSED validate_v_dummy = GFLAGS_NS::RegisterFlagValidator(
1626
    &FLAGS_v, &validate_v);
1627
1628
0
static bool PassValidate(const char*, bool) {
1629
0
    return true;
1630
0
}
1631
1632
const bool ALLOW_UNUSED validate_crash_on_fatal_log =
1633
    GFLAGS_NS::RegisterFlagValidator(&FLAGS_crash_on_fatal_log, PassValidate);
1634
1635
const bool ALLOW_UNUSED validate_print_stack_on_check =
1636
    GFLAGS_NS::RegisterFlagValidator(&FLAGS_print_stack_on_check, PassValidate);
1637
1638
0
static bool NonNegativeInteger(const char*, int32_t v) {
1639
0
    return v >= 0;
1640
0
}
1641
1642
const bool ALLOW_UNUSED validate_min_log_level = GFLAGS_NS::RegisterFlagValidator(
1643
    &FLAGS_minloglevel, NonNegativeInteger);
1644
1645
}  // namespace logging
1646
1647
0
std::ostream& operator<<(std::ostream& out, const wchar_t* wstr) {
1648
0
    return out << butil::WideToUTF8(std::wstring(wstr));
1649
0
}
1650
1651
#endif  // BRPC_WITH_GLOG