strepsirrhini/libreoffice-online
3
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions

Logging: add Area parameter and new LOGA_ macros to annotate areas.

Browse source 
Add logging.disabled_areas setting to coolwsd.xml with some sensible
things to ignore unless they are warnings/errors.

Kit code duplication around logging is grim; but not fixed in this
commit.

Signed-off-by: Michael Meeks <michael.meeks@collabora.com>
Change-Id: I36bebb2b3c8d64a814d7b10c167d582de0baf4e5
This commit is contained in:
Michael Meeks 2024-05-10 11:59:18 +01:00
parent 3cc17d6583
commit 9b6ab4c601
8 changed files with 103 additions and 27 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

38
common/Log.cpp
View file

@ -50,6 +50,9 @@ constexpr int LOG_FILE_FD = STDERR_FILENO;
} // namespace
/// Which log areas should be disabled
bool AreasDisabled[Log::AreaMax] = { false, };
/// Wrapper to expose protected 'log' and genericise
class GenericLogger : public Poco::Logger
{
@ -665,14 +668,23 @@ namespace Log
&GenericLogger::get(Static.getInited() ? Static.getName() : std::string()));
}
bool isEnabled(Level l)
bool isEnabled(Level l, Area a)
{
if (IsShutdown)
return false;
Log::Level logLevel = GenericLogger::mapToLevel(
static_cast<Poco::Message::Priority>(logger().getLevel()));
return logLevel >= static_cast<int>(l);
if (logLevel < static_cast<int>(l))
return false;
bool disabled = AreasDisabled[static_cast<size_t>(a)];
// Areas shouldn't disable warnings & errors
assert(!disabled || logLevel > static_cast<int>(Level::WRN));
return !disabled;
}
void shutdown()
@ -730,6 +742,28 @@ namespace Log
// Update our public flags in the array now ...
}
/// Set disabled areas
void setDisabledAreas(const std::string &areaStr)
{
if (areaStr != "")
LOG_INF("Setting disabled log areas to [" << areaStr << "]");
StringVector areas = StringVector::tokenize(areaStr, ',');
std::vector<bool> enabled(Log::AreaMax, true);
for (size_t t = 0; t < areas.size(); ++t)
{
for (size_t i = 0; i < Log::AreaMax; ++i)
{
if (areas.equals(t, nameShort(static_cast<Log::Area>(i))))
{
enabled[i] = false;
break;
}
}
}
for (size_t i = 0; i < Log::AreaMax; ++i)
AreasDisabled[i] = !enabled[i];
}
void log(Level l, const std::string &text)
{
Log::logger().doLog(l, text);

67
common/Log.hpp
View file

@ -28,6 +28,7 @@
#endif
#include "Util.hpp"
#include "StateEnum.hpp"
namespace Log
{
@ -44,6 +45,18 @@ namespace Log
MAX
};
// Different logging domains
STATE_ENUM(Area,
Generic,
Socket,
WebSocket,
Http,
WebServer,
Storage,
WOPI,
Admin,
Javascript);
/// Initialize the logging system.
void initialize(const std::string& name,
const std::string& logLevel,
@ -73,7 +86,7 @@ namespace Log
}
/// is a certain level of logging enabled ?
bool isEnabled(Level l);
bool isEnabled(Level l, Area a = Area::Generic);
inline bool traceEnabled()
{
@ -86,6 +99,9 @@ namespace Log
/// Setting the logging level
void setLevel(const std::string &l);
/// Set disabled areas
void setDisabledAreas(const std::string &areas);
/// Getting the logging level
Level getLevel();
@ -171,17 +187,17 @@ static constexpr std::size_t skipPathPrefix(const char (&s)[N], std::size_t n =
LOG.flush(); \
} while (false)
#define LOG_MESSAGE_(LVL, X, PREFIX, SUFFIX) \
#define LOG_MESSAGE_(LVL, A, X, PREFIX, SUFFIX) \
do \
{ \
if (LOG_CONDITIONAL(LVL)) \
if (LOG_CONDITIONAL(LVL, A)) \
{ \
LOG_BODY_(LVL, X, PREFIX, SUFFIX); \
LOG_BODY_(LVL, X, PREFIX, SUFFIX); \
} \
} while (false)
#define LOG_BODY_(LVL, X, PREFIX, END) \
#define LOG_BODY_(LVL, X, PREFIX, END) \
char b_[1024]; \
std::ostringstream oss_( \
Log::prefix<sizeof(b_) - 1>(b_, #LVL), \
@ -202,19 +218,26 @@ static constexpr std::size_t skipPathPrefix(const char (&s)[N], std::size_t n =
Log::log(Log::Level::INF, oss_.str());
#if defined __GNUC__ || defined __clang__
# define LOG_CONDITIONAL(type) \
__builtin_expect(Log::isEnabled(Log::Level::type), 0)
# define LOG_CONDITIONAL(type, area) \
__builtin_expect(Log::isEnabled(Log::Level::type, Log::Area::area), 0)
#else
# define LOG_CONDITIONAL(type) Log::isEnabled(Log::Level::type)
# define LOG_CONDITIONAL(type) Log::isEnabled(Log::Level::type, Log::Level::area)
#endif
#define LOG_TRC(X) LOG_MESSAGE_(TRC, X, logPrefix, LOG_END)
#define LOG_TRC_NOFILE(X) LOG_MESSAGE_(TRC, X, logPrefix, LOG_END_NOFILE)
#define LOG_DBG(X) LOG_MESSAGE_(DBG, X, logPrefix, LOG_END)
#define LOG_INF(X) LOG_MESSAGE_(INF, X, logPrefix, LOG_END)
#define LOG_INF_NOFILE(X) LOG_MESSAGE_(INF, X, logPrefix, LOG_END_NOFILE)
#define LOG_WRN(X) LOG_MESSAGE_(WRN, X, logPrefix, LOG_END)
#define LOG_ERR(X) LOG_MESSAGE_(ERR, X, logPrefix, LOG_END)
#define LOG_TRC(X) LOGA_TRC(Generic, X)
#define LOG_TRC_NOFILE(X) LOGA_TRC_NOFILE(Generic, X)
#define LOG_DBG(X) LOGA_DBG(Generic, X)
#define LOG_INF(X) LOGA_INF(Generic, X)
#define LOG_INF_NOFILE(X) LOGA_INF_NOFILE(Generic, X)
#define LOG_WRN(X) LOG_MESSAGE_(WRN, Generic, X, logPrefix, LOG_END)
#define LOG_ERR(X) LOG_MESSAGE_(ERR, Generic, X, logPrefix, LOG_END)
#define LOGA_TRC(A,X) LOG_MESSAGE_(TRC, A, X, logPrefix, LOG_END)
#define LOGA_TRC_NOFILE(A,X) LOG_MESSAGE_(TRC, A, X, logPrefix, LOG_END_NOFILE)
#define LOGA_DBG(A,X) LOG_MESSAGE_(DBG, A, X, logPrefix, LOG_END)
#define LOGA_INF(A,X) LOG_MESSAGE_(INF, A, X, logPrefix, LOG_END)
#define LOGA_INF_NOFILE(A,X) LOG_MESSAGE_(INF, A, X, logPrefix, LOG_END_NOFILE)
// WRN and ERR should not be filtered by area
/// Log an ERR entry with the given errno appended.
#define LOG_SYS_ERRNO(ERRNO, X) \
@ -233,9 +256,9 @@ static constexpr std::size_t skipPathPrefix(const char (&s)[N], std::size_t n =
do \
{ \
std::cerr << X << std::endl; \
if (LOG_CONDITIONAL(FTL)) \
if (LOG_CONDITIONAL(FTL, Generic)) \
{ \
LOG_BODY_(FTL, X, logPrefix, LOG_END); \
LOG_BODY_(FTL, X, logPrefix, LOG_END); \
} \
} while (false)
@ -249,11 +272,11 @@ static constexpr std::size_t skipPathPrefix(const char (&s)[N], std::size_t n =
} while (false)
/// No-prefix versions:
#define LOG_TRC_S(X) LOG_MESSAGE_(TRC, X, (void), LOG_END)
#define LOG_DBG_S(X) LOG_MESSAGE_(DBG, X, (void), LOG_END)
#define LOG_INF_S(X) LOG_MESSAGE_(INF, X, (void), LOG_END)
#define LOG_WRN_S(X) LOG_MESSAGE_(WRN, X, (void), LOG_END)
#define LOG_ERR_S(X) LOG_MESSAGE_(ERR, X, (void), LOG_END)
#define LOG_TRC_S(X) LOG_MESSAGE_(TRC, Generic, X, (void), LOG_END)
#define LOG_DBG_S(X) LOG_MESSAGE_(DBG, Generic, X, (void), LOG_END)
#define LOG_INF_S(X) LOG_MESSAGE_(INF, Generic, X, (void), LOG_END)
#define LOG_WRN_S(X) LOG_MESSAGE_(WRN, Generic, X, (void), LOG_END)
#define LOG_ERR_S(X) LOG_MESSAGE_(ERR, Generic, X, (void), LOG_END)
#define LOG_CHECK(X) \
do \

1
common/StateEnum.hpp
View file

@ -77,6 +77,7 @@
{ \
return name(e); \
} \
static const size_t NAME##Max = COUNT_ARGS(__VA_ARGS__); \
enum class NAME : char \
{ \
__VA_ARGS__ \

1
coolwsd.xml.in
View file

@ -93,6 +93,7 @@
-->
<level type="string" desc="Can be 0-8 (with the lowest numbers being the least verbose), or none (turns off logging), fatal, critical, error, warning, notice, information, debug, trace" default="@COOLWSD_LOGLEVEL@">@COOLWSD_LOGLEVEL@</level>
<level_startup type="string" desc="As for level - but for the initial startup phase which is most problematic, logging reverts to level configured above when startup is complete" default="trace">trace</level_startup>
<disabled_areas type="string" desc="High verbosity logging ie. info to trace are disable-able, comma separated: Generic, Socket, WebSocket, Http, WebServer, Storage, WOPI, Admin, Javascript" default="Socket,WebSocket,Admin">Socket,WebSocket,Admin</disabled_areas>
<most_verbose_level_settable_from_client type="string" desc="A loggingleveloverride message from the client can not set a more verbose log level than this" default="notice">notice</most_verbose_level_settable_from_client>
<least_verbose_level_settable_from_client type="string" desc="A loggingleveloverride message from a client can not set a less verbose log level than this" default="fatal">fatal</least_verbose_level_settable_from_client>
<protocol type="bool" desc="Enable minimal client-site JS protocol logging from the start">@ENABLE_DEBUG_PROTOCOL@</protocol>

10
kit/ForKit.cpp
View file

@ -63,6 +63,7 @@ static std::string UserInterface;
static bool DisplayVersion = false;
static std::string UnitTestLibrary;
static std::string LogLevel;
static std::string LogDisabledAreas;
static std::string LogLevelStartup;
static std::atomic<unsigned> ForkCounter(0);
@ -82,6 +83,7 @@ void dump_forkit_state()
oss << "Forkit: " << ForkCounter << " forks\n"
<< " LogLevel: " << LogLevel << "\n"
<< " LogDisabledAreas: " << LogDisabledAreas << "\n"
<< " LogLevelStartup: " << LogLevelStartup << "\n"
<< " unit test: " << UnitTestLibrary << "\n"
<< " NoCapsForKit: " << NoCapsForKit << "\n"
@ -420,8 +422,9 @@ static int createLibreOfficeKit(const std::string& childRoot,
pid = fork();
if (!pid)
{
// Child
sleepForDebugger();
// Child
Log::postFork();
// sort out thread local variables to get logging right from
@ -444,8 +447,6 @@ static int createLibreOfficeKit(const std::string& childRoot,
UnitKit::get().postFork();
sleepForDebugger();
lokit_main(childRoot, jailId, sysTemplate, loTemplate, NoCapsForKit, NoSeccomp,
queryVersion, DisplayVersion, spareKitId);
}
@ -603,6 +604,7 @@ int forkit_main(int argc, char** argv)
const bool logToFile = std::getenv("COOL_LOGFILE");
const char* logFilename = std::getenv("COOL_LOGFILENAME");
const char* logLevel = std::getenv("COOL_LOGLEVEL");
const char* logDisabledAreas = std::getenv("COOL_LOGDISABLED_AREAS");
const char* logLevelStartup = std::getenv("COOL_LOGLEVEL_STARTUP");
const char* logColor = std::getenv("COOL_LOGCOLOR");
std::map<std::string, std::string> logProperties;
@ -620,6 +622,7 @@ int forkit_main(int argc, char** argv)
LOG_INF("Setting log-level to [" << LogLevelStartup << " and delaying "
"setting to configured [" << LogLevel << "] until after Forkit initialization.");
}
LogDisabledAreas = logDisabledAreas ? logDisabledAreas : "";
std::string childRoot;
std::string sysTemplate;
@ -789,6 +792,7 @@ int forkit_main(int argc, char** argv)
LOG_INF("Forkit initialization complete: setting log-level to [" << LogLevel << "] as configured.");
Log::setLevel(LogLevel);
}
Log::setDisabledAreas(LogDisabledAreas);
// The SocketPoll ctor which may, depending on COOL_WATCHDOG env variable,
// want to override the SIG2 handler so set user signal handlers before

7
kit/Kit.cpp
View file

@ -2926,10 +2926,14 @@ void lokit_main(
SigUtil::setUserSignals();
}
// Are we the first ever kit ? if so, we havn't tweaked our logging by
// the time we get here; FIXME: much of this is un-necessary duplication.
// Reinitialize logging when forked.
const bool logToFile = std::getenv("COOL_LOGFILE");
const char* logFilename = std::getenv("COOL_LOGFILENAME");
const char* logLevel = std::getenv("COOL_LOGLEVEL");
const char* logDisabledAreas = std::getenv("COOL_LOGDISABLED_AREAS");
const char* logLevelStartup = std::getenv("COOL_LOGLEVEL_STARTUP");
const bool logColor = config::getBool("logging.color", true) && isatty(fileno(stderr));
std::map<std::string, std::string> logProperties;
@ -2942,6 +2946,7 @@ void lokit_main(
const std::string LogLevel = logLevel ? logLevel : "trace";
const std::string LogLevelStartup = logLevelStartup ? logLevelStartup : "trace";
const bool bTraceStartup = (std::getenv("COOL_TRACE_STARTUP") != nullptr);
Log::initialize("kit", bTraceStartup ? LogLevelStartup : logLevel, logColor, logToFile, logProperties);
if (bTraceStartup && LogLevel != LogLevelStartup)
@ -2949,6 +2954,7 @@ void lokit_main(
LOG_INF("Setting log-level to [" << LogLevelStartup << "] and delaying "
"setting to [" << LogLevel << "] until after Kit initialization.");
}
const std::string LogDisabledAreas = logDisabledAreas ? logDisabledAreas : "";
const char* pAnonymizationSalt = std::getenv("COOL_ANONYMIZATION_SALT");
if (pAnonymizationSalt)
@ -3351,6 +3357,7 @@ void lokit_main(
LOG_INF("Kit initialization complete: setting log-level to [" << LogLevel << "] as configured.");
Log::setLevel(LogLevel);
}
Log::setDisabledAreas(LogDisabledAreas);
#endif
#ifndef IOS

5
wsd/COOLWSD.cpp
View file

@ -720,6 +720,7 @@ bool COOLWSD::EnableAccessibility = false;
FILE *COOLWSD::TraceEventFile = NULL;
std::string COOLWSD::LogLevel = "trace";
std::string COOLWSD::LogLevelStartup = "trace";
std::string COOLWSD::LogDisabledAreas = "Socket,WebSocket,Admin";
std::string COOLWSD::LogToken;
std::string COOLWSD::MostVerboseLogLevelSettableFromClient = "notice";
std::string COOLWSD::LeastVerboseLogLevelSettableFromClient = "fatal";
@ -2177,10 +2178,12 @@ void COOLWSD::innerInitialize(Application& self)
// Set the log-level after complete initialization to force maximum details at startup.
LogLevel = getConfigValue<std::string>(conf, "logging.level", "trace");
LogDisabledAreas = getConfigValue<std::string>(conf, "logging.disabled_areas", "Socket,WebSocket,Admin");
MostVerboseLogLevelSettableFromClient = getConfigValue<std::string>(conf, "logging.most_verbose_level_settable_from_client", "notice");
LeastVerboseLogLevelSettableFromClient = getConfigValue<std::string>(conf, "logging.least_verbose_level_settable_from_client", "fatal");
setenv("COOL_LOGLEVEL", LogLevel.c_str(), true);
setenv("COOL_LOGDISABLED_AREAS", LogDisabledAreas.c_str(), true);
#if !ENABLE_DEBUG
const std::string salLog = getConfigValue<std::string>(conf, "logging.lokit_sal_log", "-INFO-WARN");
@ -3944,6 +3947,7 @@ public:
<< "\n ConfigFile: " << COOLWSD::ConfigFile
<< "\n ConfigDir: " << COOLWSD::ConfigDir
<< "\n LogLevel: " << COOLWSD::LogLevel
<< "\n LogDisabledAreas: " << COOLWSD::LogDisabledAreas
<< "\n AnonymizeUserData: " << (COOLWSD::AnonymizeUserData ? "yes" : "no")
<< "\n CheckCoolUser: " << (COOLWSD::CheckCoolUser ? "yes" : "no")
<< "\n IsProxyPrefixEnabled: " << (COOLWSD::IsProxyPrefixEnabled ? "yes" : "no")
@ -4279,6 +4283,7 @@ int COOLWSD::innerMain()
LOG_INF("WSD initialization complete: setting log-level to [" << LogLevel << "] as configured.");
Log::setLevel(LogLevel);
}
Log::setDisabledAreas(LogDisabledAreas);
if (Log::getLevel() >= Log::Level::INF)
LOG_ERR("Log level is set very high to '" << LogLevel << "' this will have a "

1
wsd/COOLWSD.hpp
View file

@ -281,6 +281,7 @@ public:
static void writeTraceEventRecording(const std::string &recording);
static std::string LogLevel;
static std::string LogLevelStartup;
static std::string LogDisabledAreas;
static std::string LogToken;
static std::string MostVerboseLogLevelSettableFromClient;
static std::string LeastVerboseLogLevelSettableFromClient;