[Libreoffice-commits] online.git: common/Log.cpp common/Log.hpp test/UnitAdmin.cpp test/UnitTimeout.cpp wsd/DocumentBroker.cpp wsd/QueueHandler.hpp wsd/Storage.cpp
Ashod Nakashian
ashod.nakashian at collabora.co.uk
Thu Jan 18 23:33:59 UTC 2018
common/Log.cpp | 42 ----------------------------
common/Log.hpp | 20 ++++++-------
test/UnitAdmin.cpp | 71 ++++++++++++++++++++++++++-----------------------
test/UnitTimeout.cpp | 2 -
wsd/DocumentBroker.cpp | 44 +++++++++++++++---------------
wsd/QueueHandler.hpp | 10 +++---
wsd/Storage.cpp | 2 -
7 files changed, 77 insertions(+), 114 deletions(-)
New commits:
commit c06376cc1d2e3a331e133140fc359f73783cea0e
Author: Ashod Nakashian <ashod.nakashian at collabora.co.uk>
Date: Sun Jan 14 20:39:06 2018 -0500
wsd: cleanup logging and remove unused helpers
Now all logging is done after checking if the
level in question is enabled or not (thanks to
the macros LOG_XXX), which saves unnecessary
conversions and stringification when said level
is disabled.
Change-Id: Icde31e067f60269563896f04f8b0d65643720766
Reviewed-on: https://gerrit.libreoffice.org/47885
Reviewed-by: Michael Meeks <michael.meeks at collabora.com>
Tested-by: Michael Meeks <michael.meeks at collabora.com>
diff --git a/common/Log.cpp b/common/Log.cpp
index 5a4f121f..ac05d2cc 100644
--- a/common/Log.cpp
+++ b/common/Log.cpp
@@ -182,53 +182,13 @@ namespace Log
}
oss << " Log level is [" << logger.getLevel() << "].";
- info(oss.str());
+ LOG_INF(oss.str());
}
Poco::Logger& logger()
{
return Poco::Logger::get(Source.inited ? Source.name : std::string());
}
-
- void trace(const std::string& msg)
- {
- LOG_TRC(msg);
- }
-
- void debug(const std::string& msg)
- {
- LOG_DBG(msg);
- }
-
- void info(const std::string& msg)
- {
- LOG_INF(msg);
- }
-
- void warn(const std::string& msg)
- {
- LOG_WRN(msg);
- }
-
- void error(const std::string& msg)
- {
- LOG_ERR(msg);
- }
-
- void syserror(const std::string& msg)
- {
- LOG_SYS(msg);
- }
-
- void fatal(const std::string& msg)
- {
- LOG_FTL(msg);
- }
-
- void sysfatal(const std::string& msg)
- {
- LOG_SFL(msg);
- }
}
/* vim:set shiftwidth=4 softtabstop=4 expandtab: */
diff --git a/common/Log.hpp b/common/Log.hpp
index 0be4983f..a3e4a9ae 100644
--- a/common/Log.hpp
+++ b/common/Log.hpp
@@ -22,6 +22,13 @@
#include <Poco/DateTimeFormatter.h>
#include <Poco/Logger.h>
+inline std::ostream& operator<< (std::ostream& os, const Poco::Timestamp& ts)
+{
+ os << Poco::DateTimeFormatter::format(Poco::DateTime(ts),
+ Poco::DateTimeFormat::ISO8601_FRAC_FORMAT);
+ return os;
+}
+
namespace Log
{
void initialize(const std::string& name,
@@ -33,15 +40,6 @@ namespace Log
char* prefix(char* buffer, const char* level, bool sigSafe);
- void trace(const std::string& msg);
- void debug(const std::string& msg);
- void info(const std::string& msg);
- void warn(const std::string& msg);
- void error(const std::string& msg);
- void syserror(const std::string& msg);
- void fatal(const std::string& msg);
- void sysfatal(const std::string& msg);
-
inline bool traceEnabled() { return logger().trace(); }
inline bool debugEnabled() { return logger().debug(); }
inline bool infoEnabled() { return logger().information(); }
@@ -177,8 +175,8 @@ namespace Log
{
if (lhs.enabled())
{
- lhs._stream << Poco::DateTimeFormatter::format(Poco::DateTime(rhs),
- Poco::DateTimeFormat::ISO8601_FRAC_FORMAT);
+ lhs._stream << Poco::DateTimeFormatter::format(Poco::DateTime(rhs),
+ Poco::DateTimeFormat::ISO8601_FRAC_FORMAT);
}
return lhs;
diff --git a/test/UnitAdmin.cpp b/test/UnitAdmin.cpp
index cbead413..acc058e4 100644
--- a/test/UnitAdmin.cpp
+++ b/test/UnitAdmin.cpp
@@ -79,7 +79,7 @@ private:
if (response.getStatus() == HTTPResponse::HTTP_UNAUTHORIZED)
res = TestResult::Ok;
- Log::info(std::string("testIncorrectPassword: ") + (res == TestResult::Ok ? "OK" : "FAIL"));
+ LOG_INF("testIncorrectPassword: " << (res == TestResult::Ok ? "OK" : "FAIL"));
return res;
}
@@ -117,10 +117,10 @@ private:
}
else
{
- Log::info("testCorrectPassword: Invalid cookie properties");
+ LOG_INF("testCorrectPassword: Invalid cookie properties");
}
- Log::info(std::string("testCorrectPassword: ") + (res == TestResult::Ok ? "OK" : "FAIL"));
+ LOG_INF("testCorrectPassword: " << (res == TestResult::Ok ? "OK" : "FAIL"));
return res;
}
@@ -138,7 +138,7 @@ private:
_adminWs->sendFrame(testMessage.data(), testMessage.size());
if (_messageReceivedCV.wait_for(lock, std::chrono::milliseconds(_messageTimeoutMilliSeconds)) == std::cv_status::timeout)
{
- Log::info("testWebSocketWithoutAuth: Timed out waiting for admin console message");
+ LOG_INF("testWebSocketWithoutAuth: Timed out waiting for admin console message");
return TestResult::TimedOut;
}
lock.unlock();
@@ -147,11 +147,11 @@ private:
if (tokens.count() != 1 ||
tokens[0] != "NotAuthenticated")
{
- Log::info("testWebSocketWithoutAuth: Unrecognized message format");
+ LOG_INF("testWebSocketWithoutAuth: Unrecognized message format");
return TestResult::Failed;
}
- Log::info(std::string("testWebSocketWithoutAuth: OK"));
+ LOG_INF("testWebSocketWithoutAuth: OK");
return TestResult::Ok;
}
@@ -169,7 +169,7 @@ private:
_adminWs->sendFrame(testMessage.data(), testMessage.size());
if (_messageReceivedCV.wait_for(lock, std::chrono::milliseconds(_messageTimeoutMilliSeconds)) == std::cv_status::timeout)
{
- Log::info("testWebSocketWithIncorrectAuthToken: Timed out waiting for admin console message");
+ LOG_INF("testWebSocketWithIncorrectAuthToken: Timed out waiting for admin console message");
return TestResult::TimedOut;
}
lock.unlock();
@@ -178,11 +178,11 @@ private:
if (tokens.count() != 1 ||
tokens[0] != "InvalidAuthToken")
{
- Log::info("testWebSocketWithIncorrectAuthToken: Unrecognized message format");
+ LOG_INF("testWebSocketWithIncorrectAuthToken: Unrecognized message format");
return TestResult::Failed;
}
- Log::info(std::string("testWebSocketWithIncorrectAuthToken: OK"));
+ LOG_INF("testWebSocketWithIncorrectAuthToken: OK");
return TestResult::Ok;
}
@@ -220,7 +220,7 @@ private:
_docWs1->sendFrame(loadMessage1.data(), loadMessage1.size());
if (_messageReceivedCV.wait_for(lock, std::chrono::milliseconds(_messageTimeoutMilliSeconds)) == std::cv_status::timeout)
{
- Log::info("testAddDocNotify: Timed out waiting for admin console message");
+ LOG_INF("testAddDocNotify: Timed out waiting for admin console message");
return TestResult::TimedOut;
}
lock.unlock();
@@ -231,7 +231,7 @@ private:
tokens[0] != "adddoc" ||
tokens[2] != documentPath1.substr(documentPath1.find_last_of("/") + 1) )
{
- Log::info("testAddDocNotify: Unrecognized message format");
+ LOG_INF("testAddDocNotify: Unrecognized message format");
return TestResult::Failed;
}
@@ -248,7 +248,7 @@ private:
_docWs2->sendFrame(loadMessage1.data(), loadMessage1.size());
if (_messageReceivedCV.wait_for(lock, std::chrono::milliseconds(_messageTimeoutMilliSeconds)) == std::cv_status::timeout)
{
- Log::info("testAddDocNotify: Timed out waiting for admin console message");
+ LOG_INF("testAddDocNotify: Timed out waiting for admin console message");
return TestResult::TimedOut;
}
lock.unlock();
@@ -259,7 +259,7 @@ private:
tokens[0] != "adddoc" ||
tokens[2] != documentPath1.substr(documentPath1.find_last_of("/") + 1) )
{
- Log::info("testAddDocNotify: Unrecognized message format");
+ LOG_INF("testAddDocNotify: Unrecognized message format");
return TestResult::Failed;
}
@@ -283,7 +283,7 @@ private:
_docWs3->sendFrame(loadMessage2.data(), loadMessage2.size());
if (_messageReceivedCV.wait_for(lock, std::chrono::milliseconds(_messageTimeoutMilliSeconds)) == std::cv_status::timeout)
{
- Log::info("testAddDocNotify: Timed out waiting for admin console message");
+ LOG_INF("testAddDocNotify: Timed out waiting for admin console message");
return TestResult::TimedOut;
}
lock.unlock();
@@ -294,7 +294,7 @@ private:
tokens[0] != "adddoc" ||
tokens[2] != documentPath2.substr(documentPath2.find_last_of("/") + 1) )
{
- Log::info("testAddDocNotify: Unrecognized message format");
+ LOG_INF("testAddDocNotify: Unrecognized message format");
return TestResult::Failed;
}
@@ -304,7 +304,7 @@ private:
}
_docsCount++;
- Log::info(std::string("testAddDocNotify: OK"));
+ LOG_INF("testAddDocNotify: OK");
return TestResult::Ok;
}
@@ -317,7 +317,7 @@ private:
_adminWs->sendFrame(queryMessage.data(), queryMessage.size());
if (_messageReceivedCV.wait_for(lock, std::chrono::milliseconds(_messageTimeoutMilliSeconds)) == std::cv_status::timeout)
{
- Log::info("testUsersCount: Timed out waiting for admin console message");
+ LOG_INF("testUsersCount: Timed out waiting for admin console message");
return TestResult::TimedOut;
}
lock.unlock();
@@ -326,18 +326,18 @@ private:
if (tokens.count() != 2 ||
tokens[0] != "active_users_count")
{
- Log::info("testUsersCount: Unrecognized message format");
+ LOG_INF("testUsersCount: Unrecognized message format");
return TestResult::Failed;
}
else if (std::stoi(tokens[1]) != _usersCount)
{
- Log::info("testUsersCount: Incorrect users count "
+ LOG_INF("testUsersCount: Incorrect users count "
", expected: " + std::to_string(_usersCount) +
", actual: " + tokens[1]);
return TestResult::Failed;
}
- Log::info(std::string("testUsersCount: OK"));
+ LOG_INF("testUsersCount: OK");
return TestResult::Ok;
}
@@ -350,7 +350,7 @@ private:
_adminWs->sendFrame(queryMessage.data(), queryMessage.size());
if (_messageReceivedCV.wait_for(lock, std::chrono::milliseconds(_messageTimeoutMilliSeconds)) == std::cv_status::timeout)
{
- Log::info("testDocCount: Timed out waiting for admin console message");
+ LOG_INF("testDocCount: Timed out waiting for admin console message");
return TestResult::TimedOut;
}
lock.unlock();
@@ -360,18 +360,18 @@ private:
tokens[0] != "active_docs_count" ||
std::stoi(tokens[1]) != _docsCount)
{
- Log::info("testDocCount: Unrecognized message format");
+ LOG_INF("testDocCount: Unrecognized message format");
return TestResult::Failed;
}
else if (std::stoi(tokens[1]) != _docsCount)
{
- Log::info("testDocCount: Incorrect doc count "
+ LOG_INF("testDocCount: Incorrect doc count "
", expected: " + std::to_string(_docsCount) +
", actual: " + tokens[1]);
return TestResult::Failed;
}
- Log::info(std::string("testDocCount: OK"));
+ LOG_INF("testDocCount: OK");
return TestResult::Ok;
}
@@ -386,7 +386,7 @@ private:
_docWs1->close();
if (_messageReceivedCV.wait_for(lock, std::chrono::milliseconds(_messageTimeoutMilliSeconds)) == std::cv_status::timeout)
{
- Log::info("testRmDocNotify: Timed out waiting for admin console message");
+ LOG_INF("testRmDocNotify: Timed out waiting for admin console message");
return TestResult::TimedOut;
}
lock.unlock();
@@ -396,12 +396,12 @@ private:
tokens[0] != "rmdoc" ||
stoi(tokens[1]) != _docPid1)
{
- Log::info("testRmDocNotify: Invalid message format");
+ LOG_INF("testRmDocNotify: Invalid message format");
return TestResult::Failed;
}
_usersCount--;
- Log::info(std::string("testRmDocNotify: OK"));
+ LOG_INF("testRmDocNotify: OK");
return TestResult::Ok;
}
@@ -435,12 +435,17 @@ public:
{
_isTestRunning = true;
AdminTest test = _tests[_testCounter++];
- Log::info("UnitAdmin:: Starting test #" + std::to_string(_testCounter));
+ LOG_INF("UnitAdmin:: Starting test #" << _testCounter);
TestResult res = ((*this).*(test))();
- Log::info("UnitAdmin:: Finished test #" + std::to_string(_testCounter));
+ LOG_INF("UnitAdmin:: Finished test #" << _testCounter);
if (res != TestResult::Ok)
{
- Log::info("Exiting with " + (res == TestResult::Failed ? "FAIL" : (res == TestResult::TimedOut) ? "TIMEOUT" : "??? (" + std::to_string((int)res) + ")"));
+ LOG_INF("Exiting with " <<
+ (res == TestResult::Failed
+ ? "FAIL"
+ : (res == TestResult::TimedOut)
+ ? "TIMEOUT"
+ : "??? (" + std::to_string((int)res) + ")"));
exitTest(res);
assert(false);
return;
@@ -449,7 +454,7 @@ public:
// End this when all tests are finished
if (_tests.size() == _testCounter)
{
- Log::info("Exiting with OK");
+ LOG_INF("Exiting with OK");
exitTest(TestResult::Ok);
}
@@ -462,7 +467,7 @@ public:
std::unique_lock<std::mutex> lock(_messageReceivedMutex);
_messageReceivedCV.notify_all();
_messageReceived = message;
- Log::info("UnitAdmin:: onAdminNotifyMessage: " + message);
+ LOG_INF("UnitAdmin:: onAdminNotifyMessage: " << message);
}
virtual void onAdminQueryMessage(const std::string& message)
@@ -470,7 +475,7 @@ public:
std::unique_lock<std::mutex> lock(_messageReceivedMutex);
_messageReceivedCV.notify_all();
_messageReceived = message;
- Log::info("UnitAdmin:: onAdminQueryMessage: " + message);
+ LOG_INF("UnitAdmin:: onAdminQueryMessage: " << message);
}
};
diff --git a/test/UnitTimeout.cpp b/test/UnitTimeout.cpp
index 0097d635..6c9a0519 100644
--- a/test/UnitTimeout.cpp
+++ b/test/UnitTimeout.cpp
@@ -37,7 +37,7 @@ public:
{
if (!_timedOut)
{
- Log::info("Failed to timeout");
+ LOG_INF("Failed to timeout");
retValue = Poco::Util::Application::EXIT_SOFTWARE;
}
else
diff --git a/wsd/DocumentBroker.cpp b/wsd/DocumentBroker.cpp
index 476ad544..a5f89158 100644
--- a/wsd/DocumentBroker.cpp
+++ b/wsd/DocumentBroker.cpp
@@ -544,7 +544,8 @@ bool DocumentBroker::load(const std::shared_ptr<ClientSession>& session, const s
watermarkText = LOOLWSD::OverrideWatermark;
#endif
- LOG_DBG("Setting username [" << username << "] and userId [" << userid << "] for session [" << sessionId << "]");
+ LOG_DBG("Setting username [" << username << "] and userId [" <<
+ userid << "] for session [" << sessionId << "]");
session->setUserId(userid);
session->setUserName(username);
session->setUserExtraInfo(userExtraInfo);
@@ -561,20 +562,20 @@ bool DocumentBroker::load(const std::shared_ptr<ClientSession>& session, const s
if (firstInstance)
{
_documentLastModifiedTime = fileInfo._modifiedTime;
- Log::debug() << "Document timestamp: " << _documentLastModifiedTime << Log::end;
+ LOG_DBG("Document timestamp: " << _documentLastModifiedTime);
}
else
{
// Check if document has been modified by some external action
- Log::trace() << "Document modified time: " << fileInfo._modifiedTime << Log::end;
+ LOG_TRC("Document modified time: " << fileInfo._modifiedTime);
static const Poco::Timestamp Zero(Poco::Timestamp::fromEpochTime(0));
if (_documentLastModifiedTime != Zero &&
fileInfo._modifiedTime != Zero &&
_documentLastModifiedTime != fileInfo._modifiedTime)
{
- Log::trace() << "Document " << _docKey << "] has been modified behind our back. Informing all clients."
- << "Expected: " << _documentLastModifiedTime
- << "Actual: " << fileInfo._modifiedTime << Log::end;
+ LOG_TRC("Document " << _docKey << "] has been modified behind our back. " <<
+ "Informing all clients. Expected: " << _documentLastModifiedTime <<
+ ", Actual: " << fileInfo._modifiedTime);
_documentChangedInStorage = true;
std::string message = "close: documentconflict";
@@ -596,9 +597,9 @@ bool DocumentBroker::load(const std::shared_ptr<ClientSession>& session, const s
{
try
{
- std::string extension(plugin->getString("prefilter.extension"));
- std::string newExtension(plugin->getString("prefilter.newextension"));
- std::string commandLine(plugin->getString("prefilter.commandline"));
+ const std::string extension(plugin->getString("prefilter.extension"));
+ const std::string newExtension(plugin->getString("prefilter.newextension"));
+ const std::string commandLine(plugin->getString("prefilter.commandline"));
if (localPath.length() > extension.length()+1 &&
strcasecmp(localPath.substr(localPath.length() - extension.length() -1).data(), (std::string(".") + extension).data()) == 0)
@@ -606,28 +607,28 @@ bool DocumentBroker::load(const std::shared_ptr<ClientSession>& session, const s
// Extension matches, try the conversion. We convert the file to another one in
// the same (jail) directory, with just the new extension tacked on.
- std::string newRootPath = _storage->getRootFilePath() + "." + newExtension;
+ const std::string newRootPath = _storage->getRootFilePath() + "." + newExtension;
// The commandline must contain the space-separated substring @INPUT@ that is
// replaced with the input file name, and @OUTPUT@ for the output file name.
-
- std::vector<std::string>args;
-
Poco::StringTokenizer tokenizer(commandLine, " ");
if (tokenizer.replace("@INPUT@", _storage->getRootFilePath()) != 1 ||
tokenizer.replace("@OUTPUT@", newRootPath) != 1)
throw Poco::NotFoundException();
- for (std::size_t i = 1; i < tokenizer.count(); i++)
- args.push_back(tokenizer[i]);
+
+ std::vector<std::string> args;
+ for (std::size_t i = 1; i < tokenizer.count(); ++i)
+ args.emplace_back(tokenizer[i]);
Poco::ProcessHandle process = Poco::Process::launch(tokenizer[0], args);
- int rc = process.wait();
+ const int rc = process.wait();
if (rc != 0)
{
- LOG_ERR("Conversion from " << extension << " to " << newExtension <<" failed");
+ LOG_ERR("Conversion from " << extension << " to " << newExtension << " failed (" << rc << ").");
return false;
}
+
_storage->setRootFilePath(newRootPath);
localPath += "." + newExtension;
}
@@ -783,9 +784,8 @@ bool DocumentBroker::saveToStorageInternal(const std::string& sessionId,
// After a successful save, we are sure that document in the storage is same as ours
_documentChangedInStorage = false;
- Log::debug() << "Saved docKey [" << _docKey << "] to URI [" << uri
- << "] and updated tile cache. Document modified timestamp: "
- << _documentLastModifiedTime << Log::end;
+ LOG_DBG("Saved docKey [" << _docKey << "] to URI [" << uri << "] and updated timestamps. " <<
+ " Document modified timestamp: " << _documentLastModifiedTime);
// Resume polling.
_poll->wakeup();
@@ -801,8 +801,8 @@ bool DocumentBroker::saveToStorageInternal(const std::string& sessionId,
it->second->sendTextFrame("saveas: url=" + url + " filename=" + encodedName);
- Log::debug() << "Saved As docKey [" << _docKey << "] to URI [" << url
- << " with name '" << encodedName << "'] successfully.";
+ LOG_DBG("Saved As docKey [" << _docKey << "] to URI [" << url <<
+ " with name '" << encodedName << "'] successfully.");
}
return true;
}
diff --git a/wsd/QueueHandler.hpp b/wsd/QueueHandler.hpp
index 8ef3f623..54aea6ad 100644
--- a/wsd/QueueHandler.hpp
+++ b/wsd/QueueHandler.hpp
@@ -31,7 +31,7 @@ public:
{
Util::setThreadName(_name);
- Log::debug("Thread started.");
+ LOG_DBG("Thread started.");
try
{
@@ -40,23 +40,23 @@ public:
const auto input = _queue->get();
if (LOOLProtocol::getFirstToken(input) == "eof")
{
- Log::info("Received EOF. Finishing.");
+ LOG_INF("Received EOF. Finishing.");
break;
}
if (!_session->handleInput(input.data(), input.size()))
{
- Log::info("Socket handler flagged for finishing.");
+ LOG_INF("Socket handler flagged for finishing.");
break;
}
}
}
catch (const std::exception& exc)
{
- Log::error(std::string("QueueHandler::run: Exception: ") + exc.what());
+ LOG_ERR("QueueHandler::run: Exception: " << exc.what());
}
- Log::debug("Thread finished.");
+ LOG_DBG("Thread finished.");
}
private:
diff --git a/wsd/Storage.cpp b/wsd/Storage.cpp
index 7985b42e..d5c8db6b 100644
--- a/wsd/Storage.cpp
+++ b/wsd/Storage.cpp
@@ -313,7 +313,7 @@ StorageBase::SaveResult LocalStorage::saveLocalFileToStorage(const Authorization
// update its fileinfo object. This is used later to check if someone else changed the
// document while we are/were editing it
_fileInfo._modifiedTime = Poco::File(_uri.getPath()).getLastModified();
- Log::trace() << "New FileInfo modified time in storage " << _fileInfo._modifiedTime << Log::end;
+ LOG_TRC("New FileInfo modified time in storage " << _fileInfo._modifiedTime);
}
catch (const Poco::Exception& exc)
{
More information about the Libreoffice-commits
mailing list