Simplify logging code some more. Cleaner log output on Android.

This commit is contained in:
Henrik Rydgard 2017-03-18 10:47:10 +01:00
parent a5d77f940a
commit 4f707a1022
9 changed files with 135 additions and 155 deletions

View File

@ -585,20 +585,24 @@ void ConsoleListener::PixelSpace(int Left, int Top, int Width, int Height, bool
COORD Coo = GetCoordinates(OldCursor, LBufWidth);
SetConsoleCursorPosition(hConsole, Coo);
if (SLog.length() > 0) Log(LogTypes::LNOTICE, SLog.c_str());
// if (SLog.length() > 0) Log(LogTypes::LNOTICE, SLog.c_str());
// Resize the window too
if (Resize) MoveWindow(GetConsoleWindow(), Left,Top, (Width + 100),Height, true);
#endif
}
void ConsoleListener::Log(LogTypes::LOG_LEVELS Level, const char *Text)
{
void ConsoleListener::Log(const LogMessage &msg) {
char Text[2048];
snprintf(Text, sizeof(Text), "%s %s", msg.header, msg.msg.c_str());
Text[sizeof(Text) - 2] = '\n';
Text[sizeof(Text) - 1] = '\0';
#if defined(USING_WIN_UI)
if (hThread == NULL && IsOpen())
WriteToConsole(Level, Text, strlen(Text));
WriteToConsole(msg.level, Text, strlen(Text));
else
SendToThread(Level, Text);
SendToThread(msg.level, Text);
#else
char ColorAttr[16] = "";
char ResetAttr[16] = "";

View File

@ -39,7 +39,7 @@ public:
#if defined(USING_WIN_UI)
COORD GetCoordinates(int BytesRead, int BufferWidth);
#endif
void Log(LogTypes::LOG_LEVELS, const char *Text);
void Log(const LogMessage &message);
void ClearScreen(bool Cursor = true);
void Show(bool bShow);

View File

@ -68,7 +68,7 @@ enum LOG_TYPE {
NUMBER_OF_LOGS, // Must be last
};
enum LOG_LEVELS {
enum LOG_LEVELS : int {
LNOTICE = NOTICE_LEVEL,
LERROR = ERROR_LEVEL,
LWARNING = WARNING_LEVEL,

View File

@ -24,20 +24,20 @@
#include "Timer.h"
#include "FileUtil.h"
#include "StringUtils.h"
#include "../Core/Config.h"
#include "Core/Config.h"
// Don't need to savestate this.
const char *hleCurrentThreadName = NULL;
const char *hleCurrentThreadName = nullptr;
static const char level_to_char[8] = "-NEWIDV";
// Unfortunately this is quite slow.
#define LOG_MSC_OUTPUTDEBUG false
// #define LOG_MSC_OUTPUTDEBUG true
void GenericLog(LogTypes::LOG_LEVELS level, LogTypes::LOG_TYPE type,
const char *file, int line, const char* fmt, ...) {
void GenericLog(LogTypes::LOG_LEVELS level, LogTypes::LOG_TYPE type, const char *file, int line, const char* fmt, ...) {
if (!g_Config.bEnableLogging)
return;
va_list args;
va_start(args, fmt);
LogManager *instance = LogManager::GetInstance();
@ -97,7 +97,13 @@ LogManager::LogManager() {
if (i != logTable[i].logType) {
FLOG("Bad logtable at %i", (int)i);
}
log_[logTable[i].logType] = new LogChannel(logTable[i].name);
truncate_cpy(log_[logTable[i].logType].m_shortName, logTable[i].name);
log_[logTable[i].logType].enabled = true;
#if defined(_DEBUG)
log_[logTable[i].logType].level = LogTypes::LDEBUG;
#else
log_[logTable[i].logType].level = LogTypes::LINFO;
#endif
}
// Remove file logging on small devices
@ -106,16 +112,12 @@ LogManager::LogManager() {
consoleLog_ = new ConsoleListener();
debuggerLog_ = new DebuggerLogListener();
#else
fileLog_ = NULL;
consoleLog_ = NULL;
debuggerLog_ = NULL;
fileLog_ = nullptr;
consoleLog_ = nullptr;
debuggerLog_ = nullptr;
#endif
ringLog_ = new RingbufferLogListener();
for (int i = 0; i < LogTypes::NUMBER_OF_LOGS; ++i) {
log_[i]->SetEnable(true);
}
#if !defined(MOBILE_DEVICE) || defined(_DEBUG)
AddListener(fileLog_);
AddListener(consoleLog_);
@ -139,9 +141,7 @@ LogManager::~LogManager() {
#endif
}
for (int i = 0; i < LogTypes::NUMBER_OF_LOGS; ++i)
delete log_[i];
if (fileLog_ != NULL)
if (fileLog_)
delete fileLog_;
#if !defined(MOBILE_DEVICE) || defined(_DEBUG)
delete consoleLog_;
@ -151,12 +151,12 @@ LogManager::~LogManager() {
}
void LogManager::ChangeFileLog(const char *filename) {
if (fileLog_ != NULL) {
if (fileLog_) {
RemoveListener(fileLog_);
delete fileLog_;
}
if (filename != NULL) {
if (filename) {
fileLog_ = new FileLogListener(filename);
AddListener(fileLog_);
}
@ -164,8 +164,8 @@ void LogManager::ChangeFileLog(const char *filename) {
void LogManager::SaveConfig(IniFile::Section *section) {
for (int i = 0; i < LogTypes::NUMBER_OF_LOGS; i++) {
section->Set((std::string(log_[i]->GetShortName()) + "Enabled").c_str(), log_[i]->IsEnabled());
section->Set((std::string(log_[i]->GetShortName()) + "Level").c_str(), (int)log_[i]->GetLevel());
section->Set((std::string(log_[i].m_shortName) + "Enabled").c_str(), log_[i].enabled);
section->Set((std::string(log_[i].m_shortName) + "Level").c_str(), (int)log_[i].level);
}
}
@ -173,22 +173,21 @@ void LogManager::LoadConfig(IniFile::Section *section, bool debugDefaults) {
for (int i = 0; i < LogTypes::NUMBER_OF_LOGS; i++) {
bool enabled = false;
int level = 0;
section->Get((std::string(log_[i]->GetShortName()) + "Enabled").c_str(), &enabled, true);
section->Get((std::string(log_[i]->GetShortName()) + "Level").c_str(), &level, debugDefaults ? (int)LogTypes::LDEBUG : (int)LogTypes::LERROR);
log_[i]->SetEnable(enabled);
log_[i]->SetLevel((LogTypes::LOG_LEVELS)level);
section->Get((std::string(log_[i].m_shortName) + "Enabled").c_str(), &enabled, true);
section->Get((std::string(log_[i].m_shortName) + "Level").c_str(), &level, debugDefaults ? (int)LogTypes::LDEBUG : (int)LogTypes::LERROR);
log_[i].enabled = enabled;
log_[i].level = (LogTypes::LOG_LEVELS)level;
}
}
void LogManager::Log(LogTypes::LOG_LEVELS level, LogTypes::LOG_TYPE type, const char *file, int line, const char *format, va_list args) {
LogChannel *log = log_[type];
if (level > log->GetLevel() || !log->IsEnabled())
const LogChannel &log = log_[type];
if (level > log.level || !log.enabled)
return;
std::lock_guard<std::mutex> lk(log_lock_);
static const char level_to_char[8] = "-NEWIDV";
char formattedTime[13];
Common::Timer::GetTimeFormatted(formattedTime);
LogMessage message;
message.level = level;
message.log = log.m_shortName;
#ifdef _WIN32
static const char sep = '\\';
@ -204,45 +203,46 @@ void LogManager::Log(LogTypes::LOG_LEVELS level, LogTypes::LOG_TYPE type, const
file = fileshort + 1;
}
char msg[MAX_MSGLEN];
char *msgPos = msg;
char formattedTime[13];
std::lock_guard<std::mutex> lk(log_lock_);
Common::Timer::GetTimeFormatted(formattedTime);
size_t prefixLen;
if (hleCurrentThreadName != NULL) {
prefixLen = snprintf(msgPos, MAX_MSGLEN, "%s %-12.12s %c[%s]: %s:%d ",
if (hleCurrentThreadName) {
prefixLen = snprintf(message.header, sizeof(message.header), "%s %-12.12s %c[%s]: %s:%d",
formattedTime,
hleCurrentThreadName, level_to_char[(int)level],
log->GetShortName(),
log.m_shortName,
file, line);
} else {
prefixLen = snprintf(msgPos, MAX_MSGLEN, "%s %s:%d %c[%s]: ",
prefixLen = snprintf(message.header, sizeof(message.header), "%s %s:%d %c[%s]:",
formattedTime,
file, line, level_to_char[(int)level],
log->GetShortName());
log.m_shortName);
}
msgPos += prefixLen;
size_t space = MAX_MSGLEN - prefixLen - 2;
size_t neededBytes = vsnprintf(msgPos, space, format, args);
if (neededBytes > space) {
// Cut at the end.
msg[MAX_MSGLEN - 2] = '\n';
msg[MAX_MSGLEN - 1] = '\0';
char msgBuf[1024];
size_t neededBytes = vsnprintf(msgBuf, sizeof(msgBuf), format, args);
if (neededBytes > sizeof(msgBuf)) {
// Needed more space? Re-run vsnprintf.
message.msg.resize(neededBytes + 1);
vsnprintf(&message.msg[0], neededBytes + 1, format, args);
} else {
// Plenty of space left.
msgPos[neededBytes] = '\n';
msgPos[neededBytes + 1] = '\0';
message.msg.resize(neededBytes + 1);
memcpy(&message.msg[0], msgBuf, neededBytes);
}
message.msg[message.msg.size() - 1] = '\n';
std::lock_guard<std::mutex> listeners_lock(listeners_lock_);
std::set<LogListener*>::const_iterator i;
for (i = listeners_.begin(); i != listeners_.end(); ++i) {
(*i)->Log(level, msg);
for (auto &iter : listeners_) {
iter->Log(message);
}
}
bool LogManager::IsEnabled(LogTypes::LOG_LEVELS level, LogTypes::LOG_TYPE type) {
LogChannel *log = log_[type];
if (level > log->GetLevel() || !log->IsEnabled())
LogChannel &log = log_[type];
if (level > log.level || !log.enabled)
return false;
return true;
}
@ -256,25 +256,16 @@ void LogManager::Shutdown() {
logManager_ = NULL;
}
LogChannel::LogChannel(const char* shortName)
: enable_(false) {
truncate_cpy(m_shortName, shortName);
#if defined(_DEBUG)
level_ = LogTypes::LDEBUG;
#else
level_ = LogTypes::LINFO;
#endif
}
// LogContainer
void LogManager::AddListener(LogListener *listener) {
std::lock_guard<std::mutex> lk(listeners_lock_);
listeners_.insert(listener);
listeners_.push_back(listener);
}
void LogManager::RemoveListener(LogListener *listener) {
std::lock_guard<std::mutex> lk(listeners_lock_);
listeners_.erase(listener);
auto iter = std::find(listeners_.begin(), listeners_.end(), listener);
if (iter != listeners_.end())
listeners_.erase(iter);
}
FileLogListener::FileLogListener(const char *filename) {
@ -283,32 +274,27 @@ FileLogListener::FileLogListener(const char *filename) {
#else
m_logfile.open(filename, std::ios::app);
#endif
SetEnable(true);
SetEnabled(true);
}
void FileLogListener::Log(LogTypes::LOG_LEVELS, const char *msg) {
void FileLogListener::Log(const LogMessage &message) {
if (!IsEnabled() || !IsValid())
return;
std::lock_guard<std::mutex> lk(m_log_lock);
m_logfile << msg << std::flush;
m_logfile << message.header << " " << message.msg << std::flush;
}
void DebuggerLogListener::Log(LogTypes::LOG_LEVELS, const char *msg) {
void DebuggerLogListener::Log(const LogMessage &message) {
#if _MSC_VER
OutputDebugStringUTF8(msg);
OutputDebugStringUTF8(message.msg.c_str());
#endif
}
void RingbufferLogListener::Log(LogTypes::LOG_LEVELS level, const char *msg) {
void RingbufferLogListener::Log(const LogMessage &message) {
if (!enabled_)
return;
levels_[curMessage_] = (u8)level;
size_t len = (int)strlen(msg);
if (len >= sizeof(messages_[0]))
len = sizeof(messages_[0]) - 1;
memcpy(messages_[curMessage_], msg, len);
messages_[curMessage_][len] = 0;
messages_[curMessage_] = message;
curMessage_++;
if (curMessage_ >= MAX_LOGS)
curMessage_ -= MAX_LOGS;

View File

@ -17,7 +17,7 @@
#pragma once
#include <set>
#include <vector>
#include <mutex>
#include "file/ini_file.h"
@ -26,27 +26,35 @@
#include "FileUtil.h"
#define MAX_MESSAGES 8000
#define MAX_MSGLEN 1024
extern const char *hleCurrentThreadName;
// Struct that listeners can output how they want. For example, on Android we don't want to add
// timestamp or write the level as a string, those already exist.
struct LogMessage {
char header[64]; // timestamp and the other stuff in front...
LogTypes::LOG_LEVELS level;
const char *log;
std::string msg; // The actual log message.
};
// pure virtual interface
class LogListener {
public:
virtual ~LogListener() {}
virtual void Log(LogTypes::LOG_LEVELS, const char *msg) = 0;
virtual void Log(const LogMessage &msg) = 0;
};
class FileLogListener : public LogListener {
public:
FileLogListener(const char *filename);
void Log(LogTypes::LOG_LEVELS, const char *msg);
void Log(const LogMessage &msg);
bool IsValid() { if (!m_logfile) return false; else return true; }
bool IsEnabled() const { return m_enable; }
void SetEnable(bool enable) { m_enable = enable; }
void SetEnabled(bool enable) { m_enable = enable; }
const char* GetName() const { return "file"; }
@ -58,25 +66,24 @@ private:
class DebuggerLogListener : public LogListener {
public:
void Log(LogTypes::LOG_LEVELS, const char *msg);
void Log(const LogMessage &msg);
};
class RingbufferLogListener : public LogListener {
public:
RingbufferLogListener() : curMessage_(0), count_(0), enabled_(false) {}
void Log(LogTypes::LOG_LEVELS, const char *msg);
void Log(const LogMessage &msg);
bool IsEnabled() const { return enabled_; }
void SetEnable(bool enable) { enabled_ = enable; }
void SetEnabled(bool enable) { enabled_ = enable; }
int GetCount() const { return count_ < MAX_LOGS ? count_ : MAX_LOGS; }
const char *TextAt(int i) { return messages_[(curMessage_ - i - 1) & (MAX_LOGS - 1)]; }
LogTypes::LOG_LEVELS LevelAt(int i) { return (LogTypes::LOG_LEVELS)levels_[(curMessage_ - i - 1) & (MAX_LOGS - 1)]; }
const char *TextAt(int i) const { return messages_[(curMessage_ - i - 1) & (MAX_LOGS - 1)].msg.c_str(); }
LogTypes::LOG_LEVELS LevelAt(int i) const { return messages_[(curMessage_ - i - 1) & (MAX_LOGS - 1)].level; }
private:
enum { MAX_LOGS = 128 };
char messages_[MAX_LOGS][1024];
u8 levels_[MAX_LOGS];
LogMessage messages_[MAX_LOGS];
int curMessage_;
int count_;
bool enabled_;
@ -86,33 +93,18 @@ private:
// on Android etc.
// class BufferedLogListener { ... }
class LogChannel {
public:
LogChannel(const char* shortName);
const char* GetShortName() const { return m_shortName; }
bool IsEnabled() const { return enable_; }
void SetEnable(bool enable) { enable_ = enable; }
LogTypes::LOG_LEVELS GetLevel() const { return (LogTypes::LOG_LEVELS)level_; }
void SetLevel(LogTypes::LOG_LEVELS level) { level_ = level; }
// Although not elegant, easy to set with a PopupMultiChoice...
int level_;
bool enable_;
private:
char m_shortName[32];
struct LogChannel {
char m_shortName[32]{};
LogTypes::LOG_LEVELS level;
bool enabled;
};
class ConsoleListener;
class LogManager : NonCopyable {
public:
void AddListener(LogListener* listener);
void RemoveListener(LogListener* listener);
void AddListener(LogListener *listener);
void RemoveListener(LogListener *listener);
static u32 GetMaxLevel() { return MAX_LOGLEVEL; }
static int GetNumChannels() { return LogTypes::NUMBER_OF_LOGS; }
@ -122,25 +114,25 @@ public:
bool IsEnabled(LogTypes::LOG_LEVELS level, LogTypes::LOG_TYPE type);
LogChannel *GetLogChannel(LogTypes::LOG_TYPE type) {
return log_[type];
return &log_[type];
}
void SetLogLevel(LogTypes::LOG_TYPE type, LogTypes::LOG_LEVELS level) {
log_[type]->SetLevel(level);
log_[type].level = level;
}
void SetAllLogLevels(LogTypes::LOG_LEVELS level) {
for (int i = 0; i < LogTypes::NUMBER_OF_LOGS; ++i) {
log_[i]->SetLevel(level);
log_[i].level = level;
}
}
void SetEnable(LogTypes::LOG_TYPE type, bool enable) {
log_[type]->SetEnable(enable);
void SetEnabled(LogTypes::LOG_TYPE type, bool enable) {
log_[type].enabled = enable;
}
LogTypes::LOG_LEVELS GetLogLevel(LogTypes::LOG_TYPE type) {
return log_[type]->GetLevel();
return log_[type].level;
}
ConsoleListener *GetConsoleListener() const {
@ -172,7 +164,7 @@ public:
void LoadConfig(IniFile::Section *section, bool debugDefaults);
private:
LogChannel* log_[LogTypes::NUMBER_OF_LOGS];
LogChannel log_[LogTypes::NUMBER_OF_LOGS];
FileLogListener *fileLog_;
ConsoleListener *consoleLog_;
DebuggerLogListener *debuggerLog_;
@ -181,7 +173,7 @@ private:
std::mutex log_lock_;
std::mutex listeners_lock_;
std::set<LogListener*> listeners_;
std::vector<LogListener*> listeners_;
LogManager();
~LogManager();

View File

@ -83,7 +83,7 @@ void DevMenu::CreatePopupContents(UI::ViewGroup *parent) {
RingbufferLogListener *ring = LogManager::GetInstance()->GetRingbufferListener();
if (ring) {
ring->SetEnable(true);
ring->SetEnabled(true);
}
}
@ -244,8 +244,8 @@ void LogConfigScreen::CreateViews() {
LogChannel *chan = logMan->GetLogChannel(type);
LinearLayout *row = new LinearLayout(ORIENT_HORIZONTAL, new LinearLayoutParams(cellSize - 50, WRAP_CONTENT));
row->SetSpacing(0);
row->Add(new CheckBox(&chan->enable_, "", "", new LinearLayoutParams(50, WRAP_CONTENT)));
row->Add(new PopupMultiChoice(&chan->level_, chan->GetShortName(), logLevelList, 1, 6, 0, screenManager(), new LinearLayoutParams(1.0)));
row->Add(new CheckBox(&chan->enabled, "", "", new LinearLayoutParams(50, WRAP_CONTENT)));
row->Add(new PopupMultiChoice((int *)&chan->level, chan->m_shortName, logLevelList, 1, 6, 0, screenManager(), new LinearLayoutParams(1.0)));
grid->Add(row);
}
}
@ -254,7 +254,7 @@ UI::EventReturn LogConfigScreen::OnToggleAll(UI::EventParams &e) {
LogManager *logMan = LogManager::GetInstance();
for (int i = 0; i < LogManager::GetNumChannels(); i++) {
LogChannel *chan = logMan->GetLogChannel((LogTypes::LOG_TYPE)i);
chan->enable_ = !chan->enable_;
chan->enabled = !chan->enabled;
}
return UI::EVENT_DONE;
}
@ -263,7 +263,7 @@ UI::EventReturn LogConfigScreen::OnEnableAll(UI::EventParams &e) {
LogManager *logMan = LogManager::GetInstance();
for (int i = 0; i < LogManager::GetNumChannels(); i++) {
LogChannel *chan = logMan->GetLogChannel((LogTypes::LOG_TYPE)i);
chan->enable_ = true;
chan->enabled = true;
}
return UI::EVENT_DONE;
}
@ -272,7 +272,7 @@ UI::EventReturn LogConfigScreen::OnDisableAll(UI::EventParams &e) {
LogManager *logMan = LogManager::GetInstance();
for (int i = 0; i < LogManager::GetNumChannels(); i++) {
LogChannel *chan = logMan->GetLogChannel((LogTypes::LOG_TYPE)i);
chan->enable_ = false;
chan->enabled = false;
}
return UI::EVENT_DONE;
}
@ -309,8 +309,8 @@ void LogLevelScreen::OnCompleted(DialogResult result) {
for (int i = 0; i < LogManager::GetNumChannels(); ++i) {
LogTypes::LOG_TYPE type = (LogTypes::LOG_TYPE)i;
LogChannel *chan = logMan->GetLogChannel(type);
if(chan->enable_ )
chan->level_ = selected + 1;
if (chan->enabled)
chan->level = (LogTypes::LOG_LEVELS)(selected + 1);
}
}

View File

@ -156,22 +156,23 @@ std::thread *graphicsLoadThread;
class AndroidLogger : public LogListener {
public:
void Log(LogTypes::LOG_LEVELS level, const char *msg) {
switch (level) {
void Log(const LogMessage &message) override {
// Log with simplified headers as Android already provides timestamp etc.
switch (message.level) {
case LogTypes::LVERBOSE:
case LogTypes::LDEBUG:
case LogTypes::LINFO:
ILOG("%s", msg);
ILOG("[%s] %s", message.log, message.msg.c_str());
break;
case LogTypes::LERROR:
ELOG("%s", msg);
ELOG("[%s] %s", message.log, message.msg.c_str());
break;
case LogTypes::LWARNING:
WLOG("%s", msg);
WLOG("[%s] %s", message.log, message.msg.c_str());
break;
case LogTypes::LNOTICE:
default:
ILOG("%s", msg);
ILOG("[%s] !!! %s", message.log, message.msg.c_str());
break;
}
}
@ -466,7 +467,7 @@ void NativeInit(int argc, const char *argv[], const char *savegame_dir, const ch
#ifndef _WIN32
for (int i = 0; i < LogTypes::NUMBER_OF_LOGS; i++) {
LogTypes::LOG_TYPE type = (LogTypes::LOG_TYPE)i;
logman->SetEnable(type, true);
logman->SetEnabled(type, true);
logman->SetLogLevel(type, logLevel);
#ifdef __ANDROID__
logman->AddListener(type, logger);

View File

@ -1274,9 +1274,9 @@ namespace MainWindow {
W32Util::CenterWindow(hDlg);
HWND versionBox = GetDlgItem(hDlg, IDC_VERSION);
#ifdef GOLD
std::string windowText = "PPSSPP ";
#else
std::string windowText = "PPSSPP Gold ";
#else
std::string windowText = "PPSSPP ";
#endif
windowText.append(PPSSPP_GIT_VERSION);
SetWindowText(versionBox, ConvertUTF8ToWString(windowText).c_str());

View File

@ -33,31 +33,28 @@
#include "android/android-ndk-profiler/prof.h"
#endif
class PrintfLogger : public LogListener
{
class PrintfLogger : public LogListener {
public:
void Log(LogTypes::LOG_LEVELS level, const char *msg)
{
switch (level)
{
void Log(const LogMessage &message) {
switch (message.level) {
case LogTypes::LVERBOSE:
fprintf(stderr, "V %s", msg);
fprintf(stderr, "V %s", message.msg.c_str());
break;
case LogTypes::LDEBUG:
fprintf(stderr, "D %s", msg);
fprintf(stderr, "D %s", message.msg.c_str());
break;
case LogTypes::LINFO:
fprintf(stderr, "I %s", msg);
fprintf(stderr, "I %s", message.msg.c_str());
break;
case LogTypes::LERROR:
fprintf(stderr, "E %s", msg);
fprintf(stderr, "E %s", message.msg.c_str());
break;
case LogTypes::LWARNING:
fprintf(stderr, "W %s", msg);
fprintf(stderr, "W %s", message.msg.c_str());
break;
case LogTypes::LNOTICE:
default:
fprintf(stderr, "N %s", msg);
fprintf(stderr, "N %s", message.msg.c_str());
break;
}
}
@ -299,7 +296,7 @@ int main(int argc, const char* argv[])
for (int i = 0; i < LogTypes::NUMBER_OF_LOGS; i++) {
LogTypes::LOG_TYPE type = (LogTypes::LOG_TYPE)i;
logman->SetEnable(type, fullLog);
logman->SetEnabled(type, fullLog);
logman->SetLogLevel(type, LogTypes::LDEBUG);
}
logman->AddListener(printfLogger);