Implement logging

master
Ryan Lee 2016-08-17 02:49:24 +09:00
parent aae5b22e03
commit c9ff018699
7 changed files with 1024 additions and 49 deletions

View File

@ -87,6 +87,7 @@ set(HEADERS
"src/peer.h"
"src/signalconnection.h"
"src/fakeaudiocapturemodule.h"
"src/logging.h"
)
set(SOURCES
@ -95,6 +96,7 @@ set(SOURCES
"src/peer.cc"
"src/signalconnection.cc"
"src/fakeaudiocapturemodule.cc"
"src/logging.cc"
)
# ============================================================================

View File

@ -10,6 +10,8 @@
#include "webrtc/base/json.h"
#include "webrtc/base/signalthread.h"
#include "logging.h"
#ifdef WEBRTC_POSIX
#include "webrtc/base/messagehandler.h"
#include "webrtc/base/messagequeue.h"
@ -55,7 +57,7 @@ bool Control::InitializeControl() {
webrtc::MediaConstraintsInterface* constraints = NULL;
if (!CreatePeerFactory(constraints)) {
LOG(LS_ERROR) << "CreatePeerFactory failed";
LOGP(LS_ERROR) << "CreatePeerFactory failed";
DeleteControl();
return false;
}
@ -80,7 +82,7 @@ void Control::SignIn(const std::string& user_id, const std::string& user_passwor
// 4. Generate 'signedin' event to PeerConnect
if (signal_.get() == NULL) {
LOG(LS_ERROR) << "SignIn failed, no signal server";
LOGP(LS_ERROR) << "SignIn failed, no signal server";
return;
}
@ -111,7 +113,7 @@ void Control::Connect(const std::string id) {
// 4. Conect datachannel
if (signal_.get() == NULL) {
LOG(LS_ERROR) << "Join failed, no signal server";
LOGP(LS_ERROR) << "Join failed, no signal server";
return;
}
@ -130,10 +132,13 @@ void Control::Disconnect(const std::string id) {
void Control::DisconnectAll() {
std::vector<std::string> peer_ids;
for (auto peer : peers_) {
peer_ids.push_back(peer.second->remote_id());
}
LOGP(LS_INFO) << "DisconnectAll(): peer count is " << peer_ids.size();
for (auto id : peer_ids) {
Disconnect(id);
}
@ -345,7 +350,7 @@ void Control::OnCommandReceived(const Json::Value& message) {
if (!rtc::GetStringFromJsonObject(message, "command", &command) ||
!rtc::GetValueFromJsonObject(message, "data", &data)) {
LOG(LS_ERROR) << "Invalid message:" << message;
LOGP(LS_ERROR) << "Invalid message:" << message;
return;
}
@ -388,7 +393,7 @@ void Control::OnSignalCommandReceived(const Json::Value& message) {
}
void Control::OnSignalConnectionClosed(websocketpp::close::status::value code) {
LOGP(LS_INFO) << "Calling OnSignalConnectionClosed() with " << code;
if (code == websocketpp::close::status::normal) {
ControlMessageData *data = new ControlMessageData(open_id_, ref_);
webrtc_thread_->Post(this, MSG_SIGNAL_SERVER_CLOSED, data);
@ -396,6 +401,8 @@ void Control::OnSignalConnectionClosed(websocketpp::close::status::value code) {
}
void Control::OnSignedOut(const std::string& id) {
LOGP(LS_INFO) << "Calling OnSignedOut() with " << id;
if (signal_==nullptr || signal_->opened()) return;
if (peers_.size() != 0) return;
@ -477,18 +484,18 @@ void Control::AddIceCandidate(const std::string& peer_id, const Json::Value& dat
void Control::OnSignedIn(const Json::Value& data) {
bool result;
if (!rtc::GetBoolFromJsonObject(data, "result", &result)) {
LOG(LS_WARNING) << "Unknown signin response";
LOGP(LS_WARNING) << "Unknown signin response";
return;
}
if (!result) {
LOG(LS_WARNING) << "Signin failed";
LOGP(LS_ERROR) << "Signin failed";
return;
}
std::string session_id;
if (!rtc::GetStringFromJsonObject(data, "session_id", &session_id)) {
LOG(LS_WARNING) << "Signin failed - no session_id";
LOGP(LS_ERROR) << "Signin failed - no session_id";
return;
}
@ -505,18 +512,18 @@ void Control::OnSignedIn(const Json::Value& data) {
void Control::OnChannelCreated(const Json::Value& data) {
bool result;
if (!rtc::GetBoolFromJsonObject(data, "result", &result)) {
LOG(LS_WARNING) << "Unknown signin response";
LOGP(LS_WARNING) << "Unknown signin response";
return;
}
std::string channel;
if (!rtc::GetStringFromJsonObject(data, "name", &channel)) {
LOG(LS_WARNING) << "Create channel failed - no channel name";
LOGP(LS_ERROR) << "Create channel failed - no channel name";
return;
}
if (!result) {
LOG(LS_WARNING) << "Create channel failed";
LOGP(LS_ERROR) << "Create channel failed";
std::string reason;
if (!rtc::GetStringFromJsonObject(data, "reason", &reason)) {
reason = "Unknown reason";
@ -530,19 +537,22 @@ void Control::OnChannelCreated(const Json::Value& data) {
void Control::OnChannelJoined(const Json::Value& data) {
bool result;
LOGP(LS_INFO) << "OnChannelJoined(" << data.toStyledString() << ")";
if (!rtc::GetBoolFromJsonObject(data, "result", &result)) {
LOG(LS_WARNING) << "Unknown channel join response";
LOGP(LS_ERROR) << "Unknown channel join response";
return;
}
std::string channel;
if (!rtc::GetStringFromJsonObject(data, "name", &channel)) {
LOG(LS_WARNING) << "Join channel failed - no channel name";
LOGP(LS_ERROR) << "Join channel failed - no channel name";
return;
}
if (!result) {
LOG(LS_WARNING) << "Join channel failed";
LOGP(LS_ERROR) << "Join channel failed";
std::string reason;
if (!rtc::GetStringFromJsonObject(data, "reason", &reason)) {
reason = "Unknown reason";
@ -570,14 +580,14 @@ void Control::CreateOffer(const Json::Value& data) {
Json::Value peers;
if (!rtc::GetValueFromJsonObject(data, "peers", &peers)) {
LOG(LS_WARNING) << "createoffer failed - no peers value";
LOGP(LS_ERROR) << "createoffer failed - no peers value";
return;
}
for (size_t i = 0; i < peers.size(); ++i) {
std::string remote_id;
if (!rtc::GetStringFromJsonArray(peers, i, &remote_id)) {
LOG(LS_WARNING) << "Peer handshake failed - invalid peer id";
LOGP(LS_ERROR) << "Peer handshake failed - invalid peer id";
return;
}

564
src/logging.cc Normal file
View File

@ -0,0 +1,564 @@
/*
* Copyright 2016 The PeerConnect Project Authors. All rights reserved.
*
* Ryan Lee
*/
/*
* Copyright 2004 The WebRTC Project Authors. All rights reserved.
*
* Use of this source code is governed by a BSD-style license
* that can be found in the LICENSE file in the root of the source
* tree. An additional intellectual property rights grant can be found
* in the file PATENTS. All contributing project authors may
* be found in the AUTHORS file in the root of the source tree.
*/
#if defined(WEBRTC_WIN)
#if !defined(WIN32_LEAN_AND_MEAN)
#define WIN32_LEAN_AND_MEAN
#endif
#include <windows.h>
#if _MSC_VER < 1900
#define snprintf _snprintf
#endif
#undef ERROR // wingdi.h
#endif
#if defined(WEBRTC_MAC) && !defined(WEBRTC_IOS)
#include <CoreServices/CoreServices.h>
#elif defined(WEBRTC_ANDROID)
#include <android/log.h>
// Android has a 1024 limit on log inputs. We use 60 chars as an
// approx for the header/tag portion.
// See android/system/core/liblog/logd_write.c
static const int kMaxLogLineSize = 1024 - 60;
#endif // WEBRTC_MAC && !defined(WEBRTC_IOS) || WEBRTC_ANDROID
static const char kLibjingle[] = "libjingle";
#include <time.h>
#include <limits.h>
#include <algorithm>
#include <iomanip>
#include <ostream>
#include <vector>
#include "webrtc/base/criticalsection.h"
#include "webrtc/base/platform_thread.h"
#include "webrtc/base/stringencode.h"
#include "webrtc/base/stringutils.h"
#include "webrtc/base/timeutils.h"
#include "logging.h"
using namespace rtc;
namespace pc {
namespace {
// Return the filename portion of the string (that following the last slash).
const char* FilenameFromPath(const char* file) {
const char* end1 = ::strrchr(file, '/');
const char* end2 = ::strrchr(file, '\\');
if (!end1 && !end2)
return file;
else
return (end1 > end2) ? end1 + 1 : end2 + 1;
}
} // namespace
/////////////////////////////////////////////////////////////////////////////
// Constant Labels
/////////////////////////////////////////////////////////////////////////////
const char* FindLabel(int value, const ConstantLabel entries[]) {
for (int i = 0; entries[i].label; ++i) {
if (value == entries[i].value) {
return entries[i].label;
}
}
return 0;
}
std::string ErrorName(int err, const ConstantLabel* err_table) {
if (err == 0)
return "No error";
if (err_table != 0) {
if (const char* value = FindLabel(err, err_table))
return value;
}
char buffer[16];
snprintf(buffer, sizeof(buffer), "0x%08x", err);
return buffer;
}
/////////////////////////////////////////////////////////////////////////////
// LogMessage
/////////////////////////////////////////////////////////////////////////////
// By default, release builds don't log, debug builds at info level
#if !defined(NDEBUG)
LoggingSeverity LogMessage::min_sev_ = LS_INFO;
LoggingSeverity LogMessage::dbg_sev_ = LS_INFO;
#else
LoggingSeverity LogMessage::min_sev_ = LS_NONE;
LoggingSeverity LogMessage::dbg_sev_ = LS_NONE;
#endif
bool LogMessage::log_to_stderr_ = true;
namespace {
// Global lock for log subsystem, only needed to serialize access to streams_.
CriticalSection g_log_crit;
} // namespace
// The list of logging streams currently configured.
// Note: we explicitly do not clean this up, because of the uncertain ordering
// of destructors at program exit. Let the person who sets the stream trigger
// cleanup by setting to NULL, or let it leak (safe at program exit).
LogMessage::StreamList LogMessage::streams_ GUARDED_BY(g_log_crit);
// Boolean options default to false (0)
bool LogMessage::thread_, LogMessage::timestamp_;
LogMessage::LogMessage(const char* file,
int line,
LoggingSeverity sev,
LogErrorContext err_ctx,
int err,
const char* module)
: severity_(sev), tag_(kLibjingle) {
if (timestamp_) {
int64_t time = TimeSince(LogStartTime());
// Also ensure WallClockStartTime is initialized, so that it matches
// LogStartTime.
WallClockStartTime();
print_stream_ << "[" << std::setfill('0') << std::setw(3) << (time / 1000)
<< ":" << std::setw(3) << (time % 1000) << std::setfill(' ')
<< "] ";
}
if (thread_) {
PlatformThreadId id = CurrentThreadId();
print_stream_ << "[" << std::dec << id << "] ";
}
if (file != NULL)
print_stream_ << "(" << FilenameFromPath(file) << ":" << line << "): ";
if (err_ctx != ERRCTX_NONE) {
std::ostringstream tmp;
tmp << "[0x" << std::setfill('0') << std::hex << std::setw(8) << err << "]";
switch (err_ctx) {
case ERRCTX_ERRNO:
tmp << " " << strerror(err);
break;
#if WEBRTC_WIN
case ERRCTX_HRESULT: {
char msgbuf[256];
DWORD flags = FORMAT_MESSAGE_FROM_SYSTEM;
HMODULE hmod = GetModuleHandleA(module);
if (hmod)
flags |= FORMAT_MESSAGE_FROM_HMODULE;
if (DWORD len = FormatMessageA(
flags, hmod, err,
MAKELANGID(LANG_NEUTRAL, SUBLANG_DEFAULT),
msgbuf, sizeof(msgbuf) / sizeof(msgbuf[0]), NULL)) {
while ((len > 0) &&
isspace(static_cast<unsigned char>(msgbuf[len-1]))) {
msgbuf[--len] = 0;
}
tmp << " " << msgbuf;
}
break;
}
#endif // WEBRTC_WIN
#if defined(WEBRTC_MAC) && !defined(WEBRTC_IOS)
case ERRCTX_OSSTATUS: {
std::string desc(DescriptionFromOSStatus(err));
tmp << " " << (desc.empty() ? "Unknown error" : desc.c_str());
break;
}
#endif // WEBRTC_MAC && !defined(WEBRTC_IOS)
default:
break;
}
extra_ = tmp.str();
}
}
LogMessage::LogMessage(const char* file,
int line,
LoggingSeverity sev,
const std::string& tag)
: LogMessage(file, line, sev, ERRCTX_NONE, 0 /* err */, NULL /* module */) {
tag_ = tag;
print_stream_ << tag << ": ";
}
LogMessage::~LogMessage() {
if (!extra_.empty())
print_stream_ << " : " << extra_;
print_stream_ << std::endl;
const std::string& str = print_stream_.str();
if (severity_ >= dbg_sev_) {
OutputToDebug(str, severity_, tag_);
}
CritScope cs(&g_log_crit);
for (auto& kv : streams_) {
if (severity_ >= kv.second) {
kv.first->OnLogMessage(str);
}
}
}
int64_t LogMessage::LogStartTime() {
static const int64_t g_start = TimeMillis();
return g_start;
}
uint32_t LogMessage::WallClockStartTime() {
static const uint32_t g_start_wallclock = time(NULL);
return g_start_wallclock;
}
void LogMessage::LogThreads(bool on) {
thread_ = on;
}
void LogMessage::LogTimestamps(bool on) {
timestamp_ = on;
}
void LogMessage::LogToDebug(LoggingSeverity min_sev) {
dbg_sev_ = min_sev;
CritScope cs(&g_log_crit);
UpdateMinLogSeverity();
}
void LogMessage::SetLogToStderr(bool log_to_stderr) {
log_to_stderr_ = log_to_stderr;
}
int LogMessage::GetLogToStream(LogSink* stream) {
CritScope cs(&g_log_crit);
LoggingSeverity sev = LS_NONE;
for (auto& kv : streams_) {
if (!stream || stream == kv.first) {
sev = std::min(sev, kv.second);
}
}
return sev;
}
void LogMessage::AddLogToStream(LogSink* stream, LoggingSeverity min_sev) {
CritScope cs(&g_log_crit);
streams_.push_back(std::make_pair(stream, min_sev));
UpdateMinLogSeverity();
}
void LogMessage::RemoveLogToStream(LogSink* stream) {
CritScope cs(&g_log_crit);
for (StreamList::iterator it = streams_.begin(); it != streams_.end(); ++it) {
if (stream == it->first) {
streams_.erase(it);
break;
}
}
UpdateMinLogSeverity();
}
void LogMessage::ConfigureLogging(const char* params) {
LoggingSeverity current_level = LS_VERBOSE;
LoggingSeverity debug_level = GetLogToDebug();
std::vector<std::string> tokens;
tokenize(params, ' ', &tokens);
for (const std::string& token : tokens) {
if (token.empty())
continue;
// Logging features
if (token == "tstamp") {
LogTimestamps();
} else if (token == "thread") {
LogThreads();
// Logging levels
} else if (token == "sensitive") {
current_level = LS_SENSITIVE;
} else if (token == "verbose") {
current_level = LS_VERBOSE;
} else if (token == "info") {
current_level = LS_INFO;
} else if (token == "warning") {
current_level = LS_WARNING;
} else if (token == "error") {
current_level = LS_ERROR;
} else if (token == "none") {
current_level = LS_NONE;
// Logging targets
} else if (token == "debug") {
debug_level = current_level;
}
}
#if defined(WEBRTC_WIN)
if ((LS_NONE != debug_level) && !::IsDebuggerPresent()) {
// First, attempt to attach to our parent's console... so if you invoke
// from the command line, we'll see the output there. Otherwise, create
// our own console window.
// Note: These methods fail if a console already exists, which is fine.
bool success = false;
typedef BOOL (WINAPI* PFN_AttachConsole)(DWORD);
if (HINSTANCE kernel32 = ::LoadLibrary(L"kernel32.dll")) {
// AttachConsole is defined on WinXP+.
if (PFN_AttachConsole attach_console = reinterpret_cast<PFN_AttachConsole>
(::GetProcAddress(kernel32, "AttachConsole"))) {
success = (FALSE != attach_console(ATTACH_PARENT_PROCESS));
}
::FreeLibrary(kernel32);
}
if (!success) {
::AllocConsole();
}
}
#endif // WEBRTC_WIN
LogToDebug(debug_level);
}
void LogMessage::UpdateMinLogSeverity() EXCLUSIVE_LOCKS_REQUIRED(g_log_crit) {
LoggingSeverity min_sev = dbg_sev_;
for (auto& kv : streams_) {
min_sev = std::min(dbg_sev_, kv.second);
}
min_sev_ = min_sev;
}
void LogMessage::OutputToDebug(const std::string& str,
LoggingSeverity severity,
const std::string& tag) {
bool log_to_stderr = log_to_stderr_;
#if defined(WEBRTC_MAC) && !defined(WEBRTC_IOS) && defined(NDEBUG)
// On the Mac, all stderr output goes to the Console log and causes clutter.
// So in opt builds, don't log to stderr unless the user specifically sets
// a preference to do so.
CFStringRef key = CFStringCreateWithCString(kCFAllocatorDefault,
"logToStdErr",
kCFStringEncodingUTF8);
CFStringRef domain = CFBundleGetIdentifier(CFBundleGetMainBundle());
if (key != NULL && domain != NULL) {
Boolean exists_and_is_valid;
Boolean should_log =
CFPreferencesGetAppBooleanValue(key, domain, &exists_and_is_valid);
// If the key doesn't exist or is invalid or is false, we will not log to
// stderr.
log_to_stderr = exists_and_is_valid && should_log;
}
if (key != NULL) {
CFRelease(key);
}
#endif
#if defined(WEBRTC_WIN)
// Always log to the debugger.
// Perhaps stderr should be controlled by a preference, as on Mac?
OutputDebugStringA(str.c_str());
if (log_to_stderr) {
// This handles dynamically allocated consoles, too.
if (HANDLE error_handle = ::GetStdHandle(STD_ERROR_HANDLE)) {
log_to_stderr = false;
DWORD written = 0;
::WriteFile(error_handle, str.data(), static_cast<DWORD>(str.size()),
&written, 0);
}
}
#endif // WEBRTC_WIN
#if defined(WEBRTC_ANDROID)
// Android's logging facility uses severity to log messages but we
// need to map libjingle's severity levels to Android ones first.
// Also write to stderr which maybe available to executable started
// from the shell.
int prio;
switch (severity) {
case LS_SENSITIVE:
__android_log_write(ANDROID_LOG_INFO, tag.c_str(), "SENSITIVE");
if (log_to_stderr) {
fprintf(stderr, "SENSITIVE");
fflush(stderr);
}
return;
case LS_VERBOSE:
prio = ANDROID_LOG_VERBOSE;
break;
case LS_INFO:
prio = ANDROID_LOG_INFO;
break;
case LS_WARNING:
prio = ANDROID_LOG_WARN;
break;
case LS_ERROR:
prio = ANDROID_LOG_ERROR;
break;
default:
prio = ANDROID_LOG_UNKNOWN;
}
int size = str.size();
int line = 0;
int idx = 0;
const int max_lines = size / kMaxLogLineSize + 1;
if (max_lines == 1) {
__android_log_print(prio, tag.c_str(), "%.*s", size, str.c_str());
} else {
while (size > 0) {
const int len = std::min(size, kMaxLogLineSize);
// Use the size of the string in the format (str may have \0 in the
// middle).
__android_log_print(prio, tag.c_str(), "[%d/%d] %.*s",
line + 1, max_lines,
len, str.c_str() + idx);
idx += len;
size -= len;
++line;
}
}
#endif // WEBRTC_ANDROID
if (log_to_stderr) {
fprintf(stderr, "%s", str.c_str());
fflush(stderr);
}
}
//////////////////////////////////////////////////////////////////////
// Logging Helpers
//////////////////////////////////////////////////////////////////////
void LogMultiline(LoggingSeverity level, const char* label, bool input,
const void* data, size_t len, bool hex_mode,
LogMultilineState* state) {
if (!LOGP_CHECK_LEVEL_V(level))
return;
const char * direction = (input ? " << " : " >> ");
// NULL data means to flush our count of unprintable characters.
if (!data) {
if (state && state->unprintable_count_[input]) {
LOGP_V(level) << label << direction << "## "
<< state->unprintable_count_[input]
<< " consecutive unprintable ##";
state->unprintable_count_[input] = 0;
}
return;
}
// The ctype classification functions want unsigned chars.
const unsigned char* udata = static_cast<const unsigned char*>(data);
if (hex_mode) {
const size_t LINE_SIZE = 24;
char hex_line[LINE_SIZE * 9 / 4 + 2], asc_line[LINE_SIZE + 1];
while (len > 0) {
memset(asc_line, ' ', sizeof(asc_line));
memset(hex_line, ' ', sizeof(hex_line));
size_t line_len = std::min(len, LINE_SIZE);
for (size_t i = 0; i < line_len; ++i) {
unsigned char ch = udata[i];
asc_line[i] = isprint(ch) ? ch : '.';
hex_line[i*2 + i/4] = hex_encode(ch >> 4);
hex_line[i*2 + i/4 + 1] = hex_encode(ch & 0xf);
}
asc_line[sizeof(asc_line)-1] = 0;
hex_line[sizeof(hex_line)-1] = 0;
LOGP_V(level) << label << direction
<< asc_line << " " << hex_line << " ";
udata += line_len;
len -= line_len;
}
return;
}
size_t consecutive_unprintable = state ? state->unprintable_count_[input] : 0;
const unsigned char* end = udata + len;
while (udata < end) {
const unsigned char* line = udata;
const unsigned char* end_of_line = strchrn<unsigned char>(udata,
end - udata,
'\n');
if (!end_of_line) {
udata = end_of_line = end;
} else {
udata = end_of_line + 1;
}
bool is_printable = true;
// If we are in unprintable mode, we need to see a line of at least
// kMinPrintableLine characters before we'll switch back.
const ptrdiff_t kMinPrintableLine = 4;
if (consecutive_unprintable && ((end_of_line - line) < kMinPrintableLine)) {
is_printable = false;
} else {
// Determine if the line contains only whitespace and printable
// characters.
bool is_entirely_whitespace = true;
for (const unsigned char* pos = line; pos < end_of_line; ++pos) {
if (isspace(*pos))
continue;
is_entirely_whitespace = false;
if (!isprint(*pos)) {
is_printable = false;
break;
}
}
// Treat an empty line following unprintable data as unprintable.
if (consecutive_unprintable && is_entirely_whitespace) {
is_printable = false;
}
}
if (!is_printable) {
consecutive_unprintable += (udata - line);
continue;
}
// Print out the current line, but prefix with a count of prior unprintable
// characters.
if (consecutive_unprintable) {
LOGP_V(level) << label << direction << "## " << consecutive_unprintable
<< " consecutive unprintable ##";
consecutive_unprintable = 0;
}
// Strip off trailing whitespace.
while ((end_of_line > line) && isspace(*(end_of_line-1))) {
--end_of_line;
}
// Filter out any private data
std::string substr(reinterpret_cast<const char*>(line), end_of_line - line);
std::string::size_type pos_private = substr.find("Email");
if (pos_private == std::string::npos) {
pos_private = substr.find("Passwd");
}
if (pos_private == std::string::npos) {
LOGP_V(level) << label << direction << substr;
} else {
LOGP_V(level) << label << direction << "## omitted for privacy ##";
}
}
if (state) {
state->unprintable_count_[input] = consecutive_unprintable;
}
}
//////////////////////////////////////////////////////////////////////
} // namespace pc

381
src/logging.h Normal file
View File

@ -0,0 +1,381 @@
/*
* Copyright 2016 The PeerConnect Project Authors. All rights reserved.
*
* Ryan Lee
*/
/*
* Copyright 2004 The WebRTC Project Authors. All rights reserved.
*
* Use of this source code is governed by a BSD-style license
* that can be found in the LICENSE file in the root of the source
* tree. An additional intellectual property rights grant can be found
* in the file PATENTS. All contributing project authors may
* be found in the AUTHORS file in the root of the source tree.
*/
// LOGP(...) an ostream target that can be used to send formatted
// output to a variety of logging targets, such as debugger console, stderr,
// or any LogSink.
// The severity level passed as the first argument to the LOGging
// functions is used as a filter, to limit the verbosity of the logging.
// Static members of LogMessage documented below are used to control the
// verbosity and target of the output.
// There are several variations on the LOG macro which facilitate logging
// of common error conditions, detailed below.
// LOGP(sev) logs the given stream at severity "sev", which must be a
// compile-time constant of the LoggingSeverity type, without the namespace
// prefix.
// LOGP_V(sev) Like LOGP(), but sev is a run-time variable of the LoggingSeverity
// type (basically, it just doesn't prepend the namespace).
// LOGP_F(sev) Like LOGP(), but includes the name of the current function.
// LOGP_T(sev) Like LOGP(), but includes the this pointer.
// LOGP_T_F(sev) Like LOGP_F(), but includes the this pointer.
// LOGP_GLE(M)(sev [, mod]) attempt to add a string description of the
// HRESULT returned by GetLastError. The "M" variant allows searching of a
// DLL's string table for the error description.
// LOGP_ERRNO(sev) attempts to add a string description of an errno-derived
// error. errno and associated facilities exist on both Windows and POSIX,
// but on Windows they only apply to the C/C++ runtime.
// LOGP_ERR(sev) is an alias for the platform's normal error system, i.e. _GLE on
// Windows and _ERRNO on POSIX.
// (The above three also all have _EX versions that let you specify the error
// code, rather than using the last one.)
// LOGP_E(sev, ctx, err, ...) logs a detailed error interpreted using the
// specified context.
// LOGP_CHECK_LEVEL(sev) (and LOGP_CHECK_LEVEL_V(sev)) can be used as a test
// before performing expensive or sensitive operations whose sole purpose is
// to output logging data at the desired level.
// Lastly, PLOGP(sev, err) is an alias for LOGP_ERR_EX.
#ifndef __PEERCONNECT_LOGGING_H__
#define __PEERCONNECT_LOGGING_H__
#include <errno.h>
#include <list>
#include <sstream>
#include <string>
#include <utility>
#if defined(WEBRTC_MAC) && !defined(WEBRTC_IOS)
#include <CoreServices/CoreServices.h>
#endif
#include "webrtc/base/basictypes.h"
#include "webrtc/base/constructormagic.h"
#include "webrtc/base/thread_annotations.h"
namespace pc {
///////////////////////////////////////////////////////////////////////////////
// ConstantLabel can be used to easily generate string names from constant
// values. This can be useful for logging descriptive names of error messages.
// Usage:
// const ConstantLabel LIBRARY_ERRORS[] = {
// KLABEL(SOME_ERROR),
// KLABEL(SOME_OTHER_ERROR),
// ...
// LASTLABEL
// }
//
// int err = LibraryFunc();
// LOGP(LS_ERROR) << "LibraryFunc returned: "
// << ErrorName(err, LIBRARY_ERRORS);
struct ConstantLabel { int value; const char * label; };
#ifndef KLABEL
#define KLABEL(x) { x, #x }
#define TLABEL(x, y) { x, y }
#define LASTLABEL { 0, 0 }
#endif
const char* FindLabel(int value, const ConstantLabel entries[]);
std::string ErrorName(int err, const ConstantLabel* err_table);
#if defined(WEBRTC_MAC) && !defined(WEBRTC_IOS)
// Returns a UTF8 description from an OS X Status error.
std::string DescriptionFromOSStatus(OSStatus err);
#endif
//////////////////////////////////////////////////////////////////////
// Note that the non-standard LoggingSeverity aliases exist because they are
// still in broad use. The meanings of the levels are:
// LS_SENSITIVE: Information which should only be logged with the consent
// of the user, due to privacy concerns.
// LS_VERBOSE: This level is for data which we do not want to appear in the
// normal debug log, but should appear in diagnostic logs.
// LS_INFO: Chatty level used in debugging for all sorts of things, the default
// in debug builds.
// LS_WARNING: Something that may warrant investigation.
// LS_ERROR: Something that should not have occurred.
// LS_NONE: Don't log.
enum LoggingSeverity {
LS_SENSITIVE,
LS_VERBOSE,
LS_INFO,
LS_WARNING,
LS_ERROR,
LS_NONE,
INFO = LS_INFO,
WARNING = LS_WARNING,
LERROR = LS_ERROR
};
// LogErrorContext assists in interpreting the meaning of an error value.
enum LogErrorContext {
ERRCTX_NONE,
ERRCTX_ERRNO, // System-local errno
ERRCTX_HRESULT, // Windows HRESULT
ERRCTX_OSSTATUS, // MacOS OSStatus
// Abbreviations for LOG_E macro
ERRCTX_EN = ERRCTX_ERRNO, // LOG_E(sev, EN, x)
ERRCTX_HR = ERRCTX_HRESULT, // LOG_E(sev, HR, x)
ERRCTX_OS = ERRCTX_OSSTATUS, // LOG_E(sev, OS, x)
};
// Virtual sink interface that can receive log messages.
class LogSink {
public:
LogSink() {}
virtual ~LogSink() {}
virtual void OnLogMessage(const std::string& message) = 0;
};
class LogMessage {
public:
LogMessage(const char* file, int line, LoggingSeverity sev,
LogErrorContext err_ctx = ERRCTX_NONE, int err = 0,
const char* module = NULL);
LogMessage(const char* file,
int line,
LoggingSeverity sev,
const std::string& tag);
~LogMessage();
static inline bool Loggable(LoggingSeverity sev) { return (sev >= min_sev_); }
std::ostream& stream() { return print_stream_; }
// Returns the time at which this function was called for the first time.
// The time will be used as the logging start time.
// If this is not called externally, the LogMessage ctor also calls it, in
// which case the logging start time will be the time of the first LogMessage
// instance is created.
static int64_t LogStartTime();
// Returns the wall clock equivalent of |LogStartTime|, in seconds from the
// epoch.
static uint32_t WallClockStartTime();
// LogThreads: Display the thread identifier of the current thread
static void LogThreads(bool on = true);
// LogTimestamps: Display the elapsed time of the program
static void LogTimestamps(bool on = true);
// These are the available logging channels
// Debug: Debug console on Windows, otherwise stderr
static void LogToDebug(LoggingSeverity min_sev);
static LoggingSeverity GetLogToDebug() { return dbg_sev_; }
// Sets whether logs will be directed to stderr in debug mode.
static void SetLogToStderr(bool log_to_stderr);
// Stream: Any non-blocking stream interface. LogMessage takes ownership of
// the stream. Multiple streams may be specified by using AddLogToStream.
// LogToStream is retained for backwards compatibility; when invoked, it
// will discard any previously set streams and install the specified stream.
// GetLogToStream gets the severity for the specified stream, of if none
// is specified, the minimum stream severity.
// RemoveLogToStream removes the specified stream, without destroying it.
static int GetLogToStream(LogSink* stream = NULL);
static void AddLogToStream(LogSink* stream, LoggingSeverity min_sev);
static void RemoveLogToStream(LogSink* stream);
// Testing against MinLogSeverity allows code to avoid potentially expensive
// logging operations by pre-checking the logging level.
static int GetMinLogSeverity() { return min_sev_; }
// Parses the provided parameter stream to configure the options above.
// Useful for configuring logging from the command line.
static void ConfigureLogging(const char* params);
private:
typedef std::pair<LogSink*, LoggingSeverity> StreamAndSeverity;
typedef std::list<StreamAndSeverity> StreamList;
// Updates min_sev_ appropriately when debug sinks change.
static void UpdateMinLogSeverity();
// These write out the actual log messages.
static void OutputToDebug(const std::string& msg,
LoggingSeverity severity,
const std::string& tag);
// The ostream that buffers the formatted message before output
std::ostringstream print_stream_;
// The severity level of this message
LoggingSeverity severity_;
// The Android debug output tag.
std::string tag_;
// String data generated in the constructor, that should be appended to
// the message before output.
std::string extra_;
// dbg_sev_ is the thresholds for those output targets
// min_sev_ is the minimum (most verbose) of those levels, and is used
// as a short-circuit in the logging macros to identify messages that won't
// be logged.
// ctx_sev_ is the minimum level at which file context is displayed
static LoggingSeverity min_sev_, dbg_sev_, ctx_sev_;
// The output streams and their associated severities
static StreamList streams_;
// Flags for formatting options
static bool thread_, timestamp_;
// Determines if logs will be directed to stderr in debug mode.
static bool log_to_stderr_;
RTC_DISALLOW_COPY_AND_ASSIGN(LogMessage);
};
//////////////////////////////////////////////////////////////////////
// Logging Helpers
//////////////////////////////////////////////////////////////////////
class LogMultilineState {
public:
size_t unprintable_count_[2];
LogMultilineState() {
unprintable_count_[0] = unprintable_count_[1] = 0;
}
};
// When possible, pass optional state variable to track various data across
// multiple calls to LogMultiline. Otherwise, pass NULL.
void LogMultiline(LoggingSeverity level, const char* label, bool input,
const void* data, size_t len, bool hex_mode,
LogMultilineState* state);
#ifndef LOGP
// The following non-obvious technique for implementation of a
// conditional log stream was stolen from google3/base/logging.h.
// This class is used to explicitly ignore values in the conditional
// logging macros. This avoids compiler warnings like "value computed
// is not used" and "statement has no effect".
class LogMessageVoidify {
public:
LogMessageVoidify() { }
// This has to be an operator with a precedence lower than << but
// higher than ?:
void operator&(std::ostream&) { }
};
#define LOGP_SEVERITY_PRECONDITION(sev) \
!(pc::LogMessage::Loggable(sev)) \
? (void) 0 \
: pc::LogMessageVoidify() &
#define LOGP(sev) \
LOGP_SEVERITY_PRECONDITION(pc::sev) \
pc::LogMessage(__FILE__, __LINE__, pc::sev).stream()
#define LOGP_IF(cond, sev) \
!(cond) \
? (void) 0 \
: LOGP(sev)
// The _V version is for when a variable is passed in. It doesn't do the
// namespace concatination.
#define LOGP_V(sev) \
LOGP_SEVERITY_PRECONDITION(sev) \
pc::LogMessage(__FILE__, __LINE__, sev).stream()
// The _F version prefixes the message with the current function name.
#if (defined(__GNUC__) && !defined(NDEBUG)) || defined(WANT_PRETTY_LOG_F)
#define LOGP_F(sev) LOGP(sev) << __PRETTY_FUNCTION__ << ": "
#define LOGP_T_F(sev) LOGP(sev) << this << ": " << __PRETTY_FUNCTION__ << ": "
#else
#define LOGP_F(sev) LOGP(sev) << __FUNCTION__ << ": "
#define LOGP_T_F(sev) LOGP(sev) << this << ": " << __FUNCTION__ << ": "
#endif
#define LOGP_CHECK_LEVEL(sev) \
pc::LogCheckLevel(pc::sev)
#define LOGP_CHECK_LEVEL_V(sev) \
pc::LogCheckLevel(sev)
inline bool LogCheckLevel(LoggingSeverity sev) {
return (LogMessage::GetMinLogSeverity() <= sev);
}
#define LOGP_E(sev, ctx, err, ...) \
LOGP_SEVERITY_PRECONDITION(pc::sev) \
pc::LogMessage(__FILE__, __LINE__, pc::sev, \
pc::ERRCTX_ ## ctx, err , ##__VA_ARGS__) \
.stream()
#define LOGP_T(sev) LOGP(sev) << this << ": "
#define LOGP_ERRNO_EX(sev, err) \
LOGP_E(sev, ERRNO, err)
#define LOGP_ERRNO(sev) \
LOGP_ERRNO_EX(sev, errno)
#if defined(WEBRTC_WIN)
#define LOGP_GLE_EX(sev, err) \
LOGP_E(sev, HRESULT, err)
#define LOGP_GLE(sev) \
LOGP_GLE_EX(sev, GetLastError())
#define LOGP_GLEM(sev, mod) \
LOGP_E(sev, HRESULT, GetLastError(), mod)
#define LOGP_ERR_EX(sev, err) \
LOGP_GLE_EX(sev, err)
#define LOGP_ERR(sev) \
LOGP_GLE(sev)
#define LAST_SYSTEM_ERROR \
(::GetLastError())
#elif __native_client__
#define LOGP_ERR_EX(sev, err) \
LOGP(sev)
#define LOGP_ERR(sev) \
LOGP(sev)
#define LAST_SYSTEM_ERROR \
(0)
#elif defined(WEBRTC_POSIX)
#define LOGP_ERR_EX(sev, err) \
LOGP_ERRNO_EX(sev, err)
#define LOGP_ERR(sev) \
LOGP_ERRNO(sev)
#define LAST_SYSTEM_ERROR \
(errno)
#endif // WEBRTC_WIN
#define LOGP_TAG(sev, tag) \
LOGP_SEVERITY_PRECONDITION(sev) \
pc::LogMessage(NULL, 0, sev, tag).stream()
#define PLOGP(sev, err) \
LOGP_ERR_EX(sev, err)
// TODO(?): Add an "assert" wrapper that logs in the same manner.
#endif // LOGP
} // namespace pc
#endif // __PEERCONNECT_LOGGING_H__

View File

@ -9,6 +9,7 @@
#include "webrtc/api/test/fakeconstraints.h"
#include "webrtc/api/test/mockpeerconnectionobservers.h"
#include "logging.h"
namespace pc {
@ -27,21 +28,21 @@ PeerControl::PeerControl(const std::string local_id,
peer_connection_factory_(peer_connection_factory){
if (!CreatePeerConnection()) {
LOG(LS_ERROR) << "CreatePeerConnection failed";
LOGP(LS_ERROR) << "CreatePeerConnection failed";
DeletePeerConnection();
}
webrtc::DataChannelInit init;
const std::string data_channel_name = std::string("pc_data_") + remote_id_;
if (!CreateDataChannel(data_channel_name, init)) {
LOG(LS_ERROR) << "CreateDataChannel failed";
LOGP(LS_ERROR) << "CreateDataChannel failed";
DeletePeerConnection();
}
}
PeerControl::~PeerControl() {
DeletePeerConnection();
LOG(LS_INFO) << "PeerControl has been deleted";
LOGP(LS_INFO) << "PeerControl has been deleted";
}
@ -58,8 +59,11 @@ bool PeerControl::IsWritable() {
}
void PeerControl::Close() {
local_data_channel_->Close();
remote_data_channel_->Close();
LOGP_IF(local_data_channel_ == nullptr, WARNING) << "Closing null local_data_channel";
LOGP_IF(remote_data_channel_ == nullptr, WARNING) << "Closing null remote_data_channel";
if (local_data_channel_) local_data_channel_->Close();
if (remote_data_channel_) remote_data_channel_->Close();
}
@ -180,12 +184,13 @@ void PeerControl::OnPeerClosed() {
}
// Both local_data_channel_ and remote_data_channel_ has been closed
if (local_data_channel_->state() == webrtc::DataChannelInterface::DataState::kClosed &&
remote_data_channel_->state() == webrtc::DataChannelInterface::DataState::kClosed) {
if ((local_data_channel_ == nullptr ||
local_data_channel_->state() == webrtc::DataChannelInterface::DataState::kClosed) &&
(remote_data_channel_ == nullptr ||
remote_data_channel_->state() == webrtc::DataChannelInterface::DataState::kClosed)) {
// Close local peerconnection
observer_->QueueOnPeerChannelClosed(remote_id_, 1000);
}
}
@ -282,6 +287,11 @@ void PeerControl::SetRemoteDescription(const std::string& type,
}
void PeerControl::Attach(PeerDataChannelObserver* datachannel) {
if (datachannel == nullptr) {
LOGP(WARNING) << "Attach to nullptr";
return;
}
datachannel->SignalOnOpen_.connect(this, &PeerControl::OnPeerOpened);
datachannel->SignalOnClosed_.connect(this, &PeerControl::OnPeerClosed);
datachannel->SignalOnMessage_.connect(this, &PeerControl::OnPeerMessage);
@ -289,6 +299,11 @@ void PeerControl::Attach(PeerDataChannelObserver* datachannel) {
}
void PeerControl::Detach(PeerDataChannelObserver* datachannel) {
if (datachannel == nullptr) {
LOGP(WARNING) << "Detach from nullptr";
return;
}
datachannel->SignalOnOpen_.disconnect(this);
datachannel->SignalOnClosed_.disconnect(this);
datachannel->SignalOnMessage_.disconnect(this);
@ -362,7 +377,7 @@ bool PeerDataChannelObserver::SyncSend(const char* buffer, const size_t size) {
}
void PeerDataChannelObserver::Close() {
LOG(LS_WARNING) << "Close data channel";
LOGP(LS_INFO) << "Close data channel";
if (channel_->state() != webrtc::DataChannelInterface::kClosing) {
channel_->Close();
}

View File

@ -3,12 +3,13 @@
*
* Ryan Lee
*/
#include "peerconnect.h"
#include "control.h"
#include <string>
#include <locale>
#include "peerconnect.h"
#include "control.h"
#include "logging.h"
PeerConnect::PeerConnect()
: PeerConnect(""){
@ -17,9 +18,11 @@ PeerConnect::PeerConnect()
PeerConnect::PeerConnect(const std::string setting) {
// Log level
#if DEBUG || _DEBUG
rtc::LogMessage::LogToDebug(rtc::LS_ERROR);
rtc::LogMessage::LogToDebug(rtc::LS_NONE);
pc::LogMessage::LogToDebug(pc::LS_INFO);
#else
rtc::LogMessage::LogToDebug(rtc::LS_NONE);
pc::LogMessage::LogToDebug(pc::LS_NONE);
#endif
// parse settings
@ -58,7 +61,7 @@ void PeerConnect::SignIn(const std::string alias, const std::string id, const st
//
if (control_.get() != nullptr) {
LOG(LS_ERROR) << "Already signined in.";
LOGP(LS_WARNING) << "Already signined in.";
return;
}
@ -70,7 +73,7 @@ void PeerConnect::SignIn(const std::string alias, const std::string id, const st
control_->RegisterObserver(this, control_);
if (control_.get() == NULL) {
LOG(LS_ERROR) << "Failed to create class Control.";
LOGP(LS_ERROR) << "Failed to create class Control.";
return;
}
@ -79,7 +82,7 @@ void PeerConnect::SignIn(const std::string alias, const std::string id, const st
//
if (!control_->InitializeControl()) {
LOG(LS_ERROR) << "Failed to initialize Control.";
LOGP(LS_ERROR) << "Failed to initialize Control.";
control_.reset();
return;
}
@ -245,7 +248,7 @@ bool PeerConnect::ParseSetting(const std::string& setting) {
std::string value;
if (!reader.parse(setting, jsetting)) {
LOG(WARNING) << "Invalid setting: " << setting;
LOGP(LS_WARNING) << "Invalid setting: " << setting;
return false;
}

View File

@ -36,7 +36,7 @@
#include <map>
#include <list>
#include "signalconnection.h"
#include "webrtc/base/logging.h"
#include "logging.h"
namespace pc {
@ -108,12 +108,12 @@ void Signal::SendCommand(const std::string channel,
const Json::Value& data) {
if (commandname.empty()) {
LOG(LS_WARNING) << "SendCommand with empty commandname";
LOGP(LS_WARNING) << "SendCommand with empty commandname";
return;
}
if (!opened()) {
LOG(LS_WARNING) << "Signal server is not opened";
LOGP(LS_WARNING) << "Signal server is not opened";
return;
}
@ -127,13 +127,13 @@ void Signal::SendCommand(const std::string channel,
client_.send(con_hdl_, writer.write(message), websocketpp::frame::opcode::text);
}
catch (websocketpp::lib::error_code& ec) {
LOG(LS_ERROR) << "SendCommand Error: " << ec;
LOGP(LS_ERROR) << "SendCommand Error: " << ec;
}
catch (std::exception& e) {
LOG(LS_ERROR) << "SendCommand Error: " << e.what();
LOGP(LS_ERROR) << "SendCommand Error: " << e.what();
}
catch (...) {
LOG(LS_ERROR) << "SendCommand Error: ";
LOGP(LS_ERROR) << "SendCommand Error: ";
}
}
@ -255,7 +255,7 @@ void Signal::ConnectInternal()
void Signal::CloseInternal(websocketpp::close::status::value const& code, std::string const& reason)
{
LOG(LS_INFO) << "Close by reason:" << reason;
LOGP(LS_WARNING) << "Close by reason:" << reason;
if (reconn_timer_)
{
@ -264,7 +264,7 @@ void Signal::CloseInternal(websocketpp::close::status::value const& code, std::s
}
if (con_hdl_.expired())
{
LOG(LS_ERROR) << "Error: No active session";
LOGP(LS_ERROR) << "Error: No active session";
}
else
{
@ -285,7 +285,7 @@ void Signal::TimeoutReconnect(websocketpp::lib::asio::error_code const& ec)
con_state_ = con_opening;
reconn_made_++;
this->ResetState();
LOG(LS_INFO) << "Reconnecting...";
LOGP(LS_WARNING) << "Reconnecting..";
client_.get_io_service().dispatch(websocketpp::lib::bind(&Signal::ConnectInternal, this));
}
}
@ -302,11 +302,11 @@ void Signal::OnFail(websocketpp::connection_hdl con)
{
con_hdl_.reset();
con_state_ = con_closed;
LOG(LS_ERROR) << "Connection failed.";
LOGP(LS_ERROR) << "Connection failed.";
if (reconn_made_<reconn_attempts_)
{
LOG(LS_WARNING) << "Reconnect for attempt:" << reconn_made_;
LOGP(LS_WARNING) << "Reconnect for attempt:" << reconn_made_;
unsigned delay = this->NextDelay();
reconn_timer_.reset(new asio::steady_timer(client_.get_io_service()));
websocketpp::lib::asio::error_code ec;
@ -317,7 +317,7 @@ void Signal::OnFail(websocketpp::connection_hdl con)
void Signal::OnOpen(websocketpp::connection_hdl con)
{
LOG(LS_INFO) << "Connected.";
LOGP(LS_WARNING) << "Connected.";
con_state_ = con_opened;
con_hdl_ = con;
reconn_made_ = 0;
@ -333,7 +333,7 @@ void Signal::OnClose(websocketpp::connection_hdl con)
websocketpp::close::status::value code = websocketpp::close::status::normal;
client_type::connection_ptr conn_ptr = client_.get_con_from_hdl(con, ec);
if (ec) {
LOG(LS_ERROR) << "OnClose get conn failed" << ec;
LOGP(LS_ERROR) << "OnClose get conn failed" << ec;
}
else
{
@ -352,7 +352,7 @@ void Signal::OnClose(websocketpp::connection_hdl con)
{
if (reconn_made_<reconn_attempts_)
{
LOG(LS_WARNING) << "Reconnect for attempt:" << reconn_made_;
LOGP(LS_WARNING) << "Reconnect for attempt:" << reconn_made_;
unsigned delay = this->NextDelay();
reconn_timer_.reset(new websocketpp::lib::asio::steady_timer(client_.get_io_service()));
websocketpp::lib::asio::error_code ec;
@ -370,7 +370,7 @@ void Signal::OnMessage(websocketpp::connection_hdl con, client_type::message_ptr
Json::Value jmessage;
if (!reader.parse(msg->get_payload(), jmessage)) {
LOG(WARNING) << "Received unknown message: " << msg->get_payload();
LOGP(WARNING) << "Received unknown message: " << msg->get_payload();
return;
}
@ -392,7 +392,7 @@ Signal::context_ptr Signal::OnTlsInit(websocketpp::connection_hdl conn)
asio::ssl::context::single_dh_use, ec);
if (ec)
{
LOG(LS_ERROR) << "Init tls failed,reason:" << ec.message();
LOGP(LS_ERROR) << "Init tls failed,reason:" << ec.message();
}
return ctx;