Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 765ae6bc authored by Spencer Low's avatar Spencer Low Committed by Yabin Cui
Browse files

base logging: fix errno restoring, severity conditionality, dangling ifs 



Fix LOG() to properly save and restore errno. Test this properly.

Only do logging if severity is >= the minimum.

Fix dangling if statements in CHECK(), CHECK_STR{EQ,NE}(). Test this
properly.

Fix base logging tests on Windows. All libbase_tests now pass on
Windows.

Change place to lock, so the lock can protect logging of all data in
LogMessage.

Change-Id: I7ff531c67ae10a99ef0a2bbfe279aa77282d5ae9
Signed-off-by: default avatarSpencer Low <CompareAndSwap@gmail.com>
parent 94c617cc

adb/adb_trace.h

+0 −2
Original line number Diff line number Diff line
@@ -50,9 +50,7 @@ void adb_trace_init(char**); 
#define D(...) \

        do { \

            if (ADB_TRACING) { \

                int saved_errno = errno; \

                LOG(INFO) << android::base::StringPrintf(__VA_ARGS__); \

                errno = saved_errno; \

           } \

        } while (0)

base/include/base/logging.h

+56 −18
Original line number Diff line number Diff line
@@ -87,29 +87,63 @@ extern void InitLogging(char* argv[]); 
// Replace the current logger.

extern void SetLogger(LogFunction&& logger);



// Get the minimum severity level for logging.

extern LogSeverity GetMinimumLogSeverity();



class ErrnoRestorer {

 public:

  ErrnoRestorer()

      : saved_errno_(errno) {

  }



  ~ErrnoRestorer() {

    errno = saved_errno_;

  }



  // Allow this object to evaluate to false which is useful in macros.

  operator bool() const {

    return false;

  }



 private:

  const int saved_errno_;



  DISALLOW_COPY_AND_ASSIGN(ErrnoRestorer);

};



// Logs a message to logcat on Android otherwise to stderr. If the severity is

// FATAL it also causes an abort. For example:

//

//     LOG(FATAL) << "We didn't expect to reach here";

#define LOG(severity)                                                       \

  ::android::base::LogMessage(__FILE__, __LINE__, ::android::base::DEFAULT, \

                              ::android::base::severity, -1).stream()

#define LOG(severity) LOG_TO(DEFAULT, severity)



// Logs a message to logcat with the specified log ID on Android otherwise to

// stderr. If the severity is FATAL it also causes an abort.

// Use an if-else statement instead of just an if statement here. So if there is a

// else statement after LOG() macro, it won't bind to the if statement in the macro.

// do-while(0) statement doesn't work here. Because we need to support << operator

// following the macro, like "LOG(DEBUG) << xxx;".

#define LOG_TO(dest, severity)                                                      \

  ::android::base::LogMessage(__FILE__, __LINE__, ::android::base::dest, \

  if (LIKELY(::android::base::severity < ::android::base::GetMinimumLogSeverity())) \

    ;                                                                               \

  else                                                                              \

    ::android::base::ErrnoRestorer() ? *(std::ostream*)nullptr :                    \

      ::android::base::LogMessage(__FILE__, __LINE__,                               \

          ::android::base::dest,                                                    \

          ::android::base::severity, -1).stream()



// A variant of LOG that also logs the current errno value. To be used when

// library calls fail.

#define PLOG(severity)                                                      \

  ::android::base::LogMessage(__FILE__, __LINE__, ::android::base::DEFAULT, \

                              ::android::base::severity, errno).stream()

#define PLOG(severity) PLOG_TO(DEFAULT, severity)



// Behaves like PLOG, but logs to the specified log ID.

#define PLOG_TO(dest, severity)                                                     \

  ::android::base::LogMessage(__FILE__, __LINE__, ::android::base::dest, \

  if (LIKELY(::android::base::severity < ::android::base::GetMinimumLogSeverity())) \

    ;                                                                               \

  else                                                                              \

    ::android::base::ErrnoRestorer() ? *(std::ostream*)nullptr :                    \

      ::android::base::LogMessage(__FILE__, __LINE__,                               \

          ::android::base::dest,                                                    \

          ::android::base::severity, errno).stream()



// Marker that code is yet to be implemented.
@@ -123,7 +157,9 @@ extern void SetLogger(LogFunction&& logger); 
//     CHECK(false == true) results in a log message of

//       "Check failed: false == true".

#define CHECK(x)                                                              \

  if (UNLIKELY(!(x)))                                                       \

  if (LIKELY((x)))                                                            \

    ;                                                                         \

  else                                                                        \

    ::android::base::LogMessage(__FILE__, __LINE__, ::android::base::DEFAULT, \

                                ::android::base::FATAL, -1).stream()          \

        << "Check failed: " #x << " "
@@ -153,7 +189,9 @@ extern void SetLogger(LogFunction&& logger); 


// Helper for CHECK_STRxx(s1,s2) macros.

#define CHECK_STROP(s1, s2, sense)                                         \

  if (UNLIKELY((strcmp(s1, s2) == 0) != sense))                            \

  if (LIKELY((strcmp(s1, s2) == 0) == sense))                              \

    ;                                                                      \

  else                                                                     \

    LOG(FATAL) << "Check failed: "                                         \

               << "\"" << s1 << "\""                                       \

               << (sense ? " == " : " != ") << "\"" << s2 << "\""

base/logging.cpp

+22 −35
Original line number Diff line number Diff line
@@ -139,6 +139,10 @@ static bool gInitialized = false; 
static LogSeverity gMinimumLogSeverity = INFO;

static std::unique_ptr<std::string> gProgramInvocationName;



LogSeverity GetMinimumLogSeverity() {

  return gMinimumLogSeverity;

}



static const char* ProgramInvocationName() {

  if (gProgramInvocationName == nullptr) {

    gProgramInvocationName.reset(new std::string(getprogname()));
@@ -200,20 +204,6 @@ void InitLogging(char* argv[], LogFunction&& logger) { 
  InitLogging(argv);

}



// TODO: make this public; it's independently useful.

class ErrnoRestorer {

 public:

  ErrnoRestorer(int saved_errno) : saved_errno_(saved_errno) {

  }



  ~ErrnoRestorer() {

    errno = saved_errno_;

  }



 private:

  const int saved_errno_;

};



void InitLogging(char* argv[]) {

  if (gInitialized) {

    return;
@@ -286,13 +276,12 @@ static const char* GetFileBasename(const char* file) { 
class LogMessageData {

 public:

  LogMessageData(const char* file, unsigned int line, LogId id,

                 LogSeverity severity, int error, int saved_errno)

                 LogSeverity severity, int error)

      : file_(GetFileBasename(file)),

        line_number_(line),

        id_(id),

        severity_(severity),

        error_(error),

        errno_restorer_(saved_errno) {

        error_(error) {

  }



  const char* GetFile() const {
@@ -330,27 +319,25 @@ class LogMessageData { 
  const LogId id_;

  const LogSeverity severity_;

  const int error_;

  ErrnoRestorer errno_restorer_;



  DISALLOW_COPY_AND_ASSIGN(LogMessageData);

};



LogMessage::LogMessage(const char* file, unsigned int line, LogId id,

                       LogSeverity severity, int error)

    : data_(new LogMessageData(file, line, id, severity, error, errno)) {

    : data_(new LogMessageData(file, line, id, severity, error)) {

}



LogMessage::~LogMessage() {

  if (data_->GetSeverity() < gMinimumLogSeverity) {

    return;  // No need to format something we're not going to output.

  }



  // Finish constructing the message.

  if (data_->GetError() != -1) {

    data_->GetBuffer() << ": " << strerror(data_->GetError());

  }

  std::string msg(data_->ToString());



  {

    // Do the actual logging with the lock held.

    lock_guard<mutex> lock(logging_lock);

    if (msg.find('\n') == std::string::npos) {

      LogLine(data_->GetFile(), data_->GetLineNumber(), data_->GetId(),

              data_->GetSeverity(), msg.c_str());
@@ -365,6 +352,7 @@ LogMessage::~LogMessage() { 
        i = nl + 1;

      }

    }

  }



  // Abort if necessary.

  if (data_->GetSeverity() == FATAL) {
@@ -382,7 +370,6 @@ std::ostream& LogMessage::stream() { 
void LogMessage::LogLine(const char* file, unsigned int line, LogId id,

                         LogSeverity severity, const char* message) {

  const char* tag = ProgramInvocationName();

  lock_guard<mutex> lock(logging_lock);

  gLogger(id, severity, tag, file, line, message);

}

base/logging_test.cpp

+94 −4
Original line number Diff line number Diff line
@@ -18,6 +18,10 @@ 


#include <libgen.h>



#if defined(_WIN32)

#include <signal.h>

#endif



#include <regex>

#include <string>
@@ -49,6 +53,11 @@ class CapturedStderr { 


 private:

  void init() {

#if defined(_WIN32)

    // On Windows, stderr is often buffered, so make sure it is unbuffered so

    // that we can immediately read back what was written to stderr.

    ASSERT_EQ(0, setvbuf(stderr, NULL, _IONBF, 0));

#endif

    old_stderr_ = dup(STDERR_FILENO);

    ASSERT_NE(-1, old_stderr_);

    ASSERT_NE(-1, dup2(fd(), STDERR_FILENO));
@@ -57,21 +66,58 @@ class CapturedStderr { 
  void reset() {

    ASSERT_NE(-1, dup2(old_stderr_, STDERR_FILENO));

    ASSERT_EQ(0, close(old_stderr_));

    // Note: cannot restore prior setvbuf() setting.

  }



  TemporaryFile temp_file_;

  int old_stderr_;

};



#if defined(_WIN32)

static void ExitSignalAbortHandler(int) {

  _exit(3);

}

#endif



static void SuppressAbortUI() {

#if defined(_WIN32)

  // We really just want to call _set_abort_behavior(0, _CALL_REPORTFAULT) to

  // suppress the Windows Error Reporting dialog box, but that API is not

  // available in the OS-supplied C Runtime, msvcrt.dll, that we currently

  // use (it is available in the Visual Studio C runtime).

  //

  // Instead, we setup a SIGABRT handler, which is called in abort() right

  // before calling Windows Error Reporting. In the handler, we exit the

  // process just like abort() does.

  ASSERT_NE(SIG_ERR, signal(SIGABRT, ExitSignalAbortHandler));

#endif

}



TEST(logging, CHECK) {

  ASSERT_DEATH(CHECK(false), "Check failed: false ");

  ASSERT_DEATH({SuppressAbortUI(); CHECK(false);}, "Check failed: false ");

  CHECK(true);



  ASSERT_DEATH(CHECK_EQ(0, 1), "Check failed: 0 == 1 ");

  ASSERT_DEATH({SuppressAbortUI(); CHECK_EQ(0, 1);}, "Check failed: 0 == 1 ");

  CHECK_EQ(0, 0);



  ASSERT_DEATH(CHECK_STREQ("foo", "bar"), R"(Check failed: "foo" == "bar")");

  ASSERT_DEATH({SuppressAbortUI(); CHECK_STREQ("foo", "bar");},

               R"(Check failed: "foo" == "bar")");

  CHECK_STREQ("foo", "foo");



  // Test whether CHECK() and CHECK_STREQ() have a dangling if with no else.

  bool flag = false;

  if (true)

    CHECK(true);

  else

    flag = true;

  EXPECT_FALSE(flag) << "CHECK macro probably has a dangling if with no else";



  flag = false;

  if (true)

    CHECK_STREQ("foo", "foo");

  else

    flag = true;

  EXPECT_FALSE(flag) << "CHECK_STREQ probably has a dangling if with no else";

}



std::string make_log_pattern(android::base::LogSeverity severity,
@@ -85,7 +131,7 @@ std::string make_log_pattern(android::base::LogSeverity severity, 
}



TEST(logging, LOG) {

  ASSERT_DEATH(LOG(FATAL) << "foobar", "foobar");

  ASSERT_DEATH({SuppressAbortUI(); LOG(FATAL) << "foobar";}, "foobar");



  // We can't usefully check the output of any of these on Windows because we

  // don't have std::regex, but we can at least make sure we printed at least as
@@ -148,6 +194,50 @@ TEST(logging, LOG) { 
    ASSERT_TRUE(std::regex_search(output, message_regex)) << output;

#endif

  }



  // Test whether LOG() saves and restores errno.

  {

    CapturedStderr cap;

    errno = 12345;

    LOG(INFO) << (errno = 67890);

    EXPECT_EQ(12345, errno) << "errno was not restored";



    ASSERT_EQ(0, lseek(cap.fd(), SEEK_SET, 0));



    std::string output;

    android::base::ReadFdToString(cap.fd(), &output);

    EXPECT_NE(nullptr, strstr(output.c_str(), "67890")) << output;



#if !defined(_WIN32)

    std::regex message_regex(

        make_log_pattern(android::base::INFO, "67890"));

    ASSERT_TRUE(std::regex_search(output, message_regex)) << output;

#endif

  }



  // Test whether LOG() has a dangling if with no else.

  {

    CapturedStderr cap;



    // Do the test two ways: once where we hypothesize that LOG()'s if

    // will evaluate to true (when severity is high enough) and once when we

    // expect it to evaluate to false (when severity is not high enough).

    bool flag = false;

    if (true)

      LOG(INFO) << "foobar";

    else

      flag = true;



    EXPECT_FALSE(flag) << "LOG macro probably has a dangling if with no else";



    flag = false;

    if (true)

      LOG(VERBOSE) << "foobar";

    else

      flag = true;



    EXPECT_FALSE(flag) << "LOG macro probably has a dangling if with no else";

  }

}



TEST(logging, PLOG) {