[Libreoffice-commits] online.git: loolwsd/ChildProcessSession.cpp loolwsd/LOOLBroker.cpp loolwsd/LOOLKit.cpp loolwsd/LOOLSession.cpp loolwsd/LOOLWSD.cpp loolwsd/MasterProcessSession.cpp loolwsd/Util.cpp loolwsd/Util.hpp
Ashod Nakashian
ashod.nakashian at collabora.co.uk
Thu Dec 24 19:32:51 PST 2015
loolwsd/ChildProcessSession.cpp | 9 +-
loolwsd/LOOLBroker.cpp | 148 ++++++++++++++++++---------------------
loolwsd/LOOLKit.cpp | 16 +---
loolwsd/LOOLSession.cpp | 20 +++--
loolwsd/LOOLWSD.cpp | 37 ++++-----
loolwsd/MasterProcessSession.cpp | 17 ++--
loolwsd/Util.cpp | 39 ++++++----
loolwsd/Util.hpp | 80 +++++++++++++++++++++
8 files changed, 227 insertions(+), 139 deletions(-)
New commits:
commit 8464651655baf9056b9432fc87fd999a4aa438a8
Author: Ashod Nakashian <ashod.nakashian at collabora.co.uk>
Date: Thu Dec 24 22:19:50 2015 -0500
loolwsd: Better logging
Color logging in console, tracing and streaming,
and converted cout to proper logging.
Change-Id: I515b8f8a40f8fa6763536b85c7632e3bb36673ee
Reviewed-on: https://gerrit.libreoffice.org/20931
Reviewed-by: Ashod Nakashian <ashnakash at gmail.com>
Tested-by: Ashod Nakashian <ashnakash at gmail.com>
diff --git a/loolwsd/ChildProcessSession.cpp b/loolwsd/ChildProcessSession.cpp
index f074eb5..2926437 100644
--- a/loolwsd/ChildProcessSession.cpp
+++ b/loolwsd/ChildProcessSession.cpp
@@ -52,12 +52,12 @@ ChildProcessSession::ChildProcessSession(std::shared_ptr<WebSocket> ws,
_childId(childId),
_clientPart(0)
{
- std::cout << Util::logPrefix() << "ChildProcessSession ctor this=" << this << " ws=" << _ws.get() << std::endl;
+ Log::info() << "ChildProcessSession ctor this:" << this << " ws:" << _ws.get() << Log::end;
}
ChildProcessSession::~ChildProcessSession()
{
- std::cout << Util::logPrefix() << "ChildProcessSession dtor this=" << this << std::endl;
+ Log::info() << "ChildProcessSession dtor this:" << this << " ws: " << _ws.get() << Log::end;
if (LIBREOFFICEKIT_HAS(_loKit, registerCallback))
_loKit->pClass->registerCallback(_loKit, 0, 0);
Util::shutdownWebSocket(*_ws);
@@ -314,7 +314,7 @@ void ChildProcessSession::sendFontRendering(const char* /*buffer*/, int /*length
Poco::Timestamp timestamp;
pixmap = _loKitDocument->pClass->renderFont(_loKitDocument, decodedFont.c_str(), &width, &height);
- std::cout << Util::logPrefix() << "renderFont called, font[" << font << "] rendered in " << double(timestamp.elapsed())/1000 << "ms" << std::endl;
+ Log::trace("renderFont [" + font + "] rendered in " + std::to_string(timestamp.elapsed()/1000.) + "ms");
if (pixmap != nullptr)
{
@@ -407,7 +407,8 @@ void ChildProcessSession::sendTile(const char* /*buffer*/, int /*length*/, Strin
Poco::Timestamp timestamp;
_loKitDocument->pClass->paintTile(_loKitDocument, pixmap, width, height, tilePosX, tilePosY, tileWidth, tileHeight);
- std::cout << Util::logPrefix() << "paintTile called, tile at [" << tilePosX << ", " << tilePosY << "] rendered in " << double(timestamp.elapsed())/1000 << "ms" << std::endl;
+ Log::trace() << "paintTile at [" << tilePosX << ", " << tilePosY
+ << "] rendered in " << (timestamp.elapsed()/1000.) << " ms" << Log::end;
LibreOfficeKitTileMode mode = static_cast<LibreOfficeKitTileMode>(_loKitDocument->pClass->getTileMode(_loKitDocument));
if (!Util::encodePNGAndAppendToBuffer(pixmap, width, height, output, mode))
diff --git a/loolwsd/LOOLBroker.cpp b/loolwsd/LOOLBroker.cpp
index de645c6..1862aa5 100644
--- a/loolwsd/LOOLBroker.cpp
+++ b/loolwsd/LOOLBroker.cpp
@@ -106,9 +106,8 @@ namespace
File(newPath.parent()).createDirectories();
if (link(fpath, newPath.toString().c_str()) == -1)
{
- std::cout << Util::logPrefix() +
- "link(\"" + fpath + "\",\"" + newPath.toString() + "\") failed: " +
- strerror(errno) << std::endl;
+ Log::error("Error: link(\"" + std::string(fpath) + "\",\"" + newPath.toString() +
+ "\") failed. Exiting.");
exit(1);
}
break;
@@ -117,9 +116,7 @@ namespace
struct stat st;
if (stat(fpath, &st) == -1)
{
- std::cout << Util::logPrefix() +
- "stat(\"" + fpath + "\") failed: " +
- strerror(errno) << std::endl;
+ Log::error("Error: stat(\"" + std::string(fpath) + "\") failed.");
return 1;
}
File(newPath).createDirectories();
@@ -128,9 +125,7 @@ namespace
ut.modtime = st.st_mtime;
if (utime(newPath.toString().c_str(), &ut) == -1)
{
- std::cout << Util::logPrefix() +
- "utime(\"" + newPath.toString() + "\", &ut) failed: " +
- strerror(errno) << std::endl;
+ Log::error("Error: utime(\"" + newPath.toString() + "\", &ut) failed.");
return 1;
}
}
@@ -177,20 +172,20 @@ namespace
caps = cap_get_proc();
if (caps == NULL)
{
- std::cout << Util::logPrefix() + "cap_get_proc() failed: " + strerror(errno) << std::endl;
+ Log::error("Error: cap_get_proc() failed.");
exit(1);
}
if (cap_set_flag(caps, CAP_EFFECTIVE, sizeof(cap_list)/sizeof(cap_list[0]), cap_list, CAP_CLEAR) == -1 ||
cap_set_flag(caps, CAP_PERMITTED, sizeof(cap_list)/sizeof(cap_list[0]), cap_list, CAP_CLEAR) == -1)
{
- std::cout << Util::logPrefix() + "cap_set_flag() failed: " + strerror(errno) << std::endl;
+ Log::error("Error: cap_set_flag() failed.");
exit(1);
}
if (cap_set_proc(caps) == -1)
{
- std::cout << Util::logPrefix() << std::string("cap_set_proc() failed: ") + strerror(errno) << std::endl;
+ Log::error("Error: cap_set_proc() failed.");
exit(1);
}
@@ -209,7 +204,7 @@ namespace
// to do chroot().
if (setuid(getuid()) != 0)
{
- std::cout << Util::logPrefix() << std::string("setuid() failed: ") + strerror(errno) << std::endl;
+ Log::error("Error: setuid() failed.");
}
}
#if ENABLE_DEBUG
@@ -233,7 +228,7 @@ namespace
}
if (setuid(LOOLWSD::uid) != 0)
{
- Log::error(std::string("setuid() failed: ") + strerror(errno));
+ Log::error("Error: setuid() failed.");
}
}
#endif
@@ -294,7 +289,7 @@ public:
nBytes = Util::writeFIFO(nPipeWriter, aMessage.c_str(), aMessage.length());
if ( nBytes < 0 )
- std::cout << Util::logPrefix() << "Error writting child: " << strerror(errno) << std::endl;
+ Log::error("Error writting to child pipe.");
return nBytes;
}
@@ -325,25 +320,25 @@ public:
{
if ( !(aIterator->first > 0 && aIterator->second > 0) )
{
- //std::cout << Util::logPrefix() << "error iterator " << aIterator->second << " " << aMessage << std::endl;
+ //Log::error("error iterator " + aIterator->second + " " + aMessage);
continue;
}
nBytes = Util::writeFIFO(aIterator->second, aMessage.c_str(), aMessage.length());
if ( nBytes < 0 )
{
- std::cout << Util::logPrefix() << "Error writting child: " << aIterator->first << " " << strerror(errno) << std::endl;
+ Log::error("Error writting to child pipe: " + std::to_string(aIterator->first) + ".");
break;
}
nBytes = getResponseLine(readerChild, aResponse);
if ( nBytes < 0 )
{
- std::cout << Util::logPrefix() << "Error reading child: " << aIterator->first << " " << strerror(errno) << std::endl;
+ Log::error("Error reading child response: " + std::to_string(aIterator->first) + ".");
break;
}
- //std::cout << Util::logPrefix() << "response: " << aResponse << std::endl;
+ //Log::trace("response: " << aResponse);
StringTokenizer tokens(aResponse, " ", StringTokenizer::TOK_IGNORE_EMPTY | StringTokenizer::TOK_TRIM);
if (tokens[1] == "ok")
{
@@ -378,9 +373,10 @@ public:
auto aIterURL = _cacheURL.find(aURL);
if ( aIterURL != _cacheURL.end() )
{
- std::cout << Util::logPrefix() << "Cache Found: " << aIterURL->first << std::endl;
+ Log::debug("Cache found URL [" + aURL + "] hosted on child [" + std::to_string(aIterURL->second) +
+ "]. Creating view for thread [" + aTID + "].");
if (createThread(aIterURL->second, aTID) < 0)
- std::cout << Util::logPrefix() << "Cache: Error creating thread: " << strerror(errno) << std::endl;
+ Log::error("Cache: Error creating thread.");
return;
}
@@ -392,9 +388,10 @@ public:
if ( nPID > 0 )
{
- std::cout << Util::logPrefix() << "Search Found: " << nPID << std::endl;
+ Log::debug("Search found URL [" + aURL + "] hosted by child [" + std::to_string(nPID) +
+ "]. Creating view for thread [" + aTID + "].");
if (createThread(nPID, aTID) < 0)
- std::cout << Util::logPrefix() << "Search: Error creating thread: " << strerror(errno) << std::endl;
+ Log::error("Search: Error creating thread.");
else
_cacheURL[aURL] = nPID;
@@ -404,17 +401,17 @@ public:
// not found, new URL session.
if ( _emptyURL.size() > 0 )
{
- auto aItem = _emptyURL.front();
- std::cout << Util::logPrefix() << "Not Found: " << aItem << std::endl;
+ const auto aItem = _emptyURL.front();
+ Log::trace("No child found.");
if (updateURL(aItem, aURL) < 0)
{
- std::cout << Util::logPrefix() << "New: Error update URL: " << strerror(errno) << std::endl;
+ Log::error("New: Error update URL.");
return;
}
if (createThread(aItem, aTID) < 0)
{
- std::cout << Util::logPrefix() << "New: Error creating thread: " << strerror(errno) << std::endl;
+ Log::error("New: Error creating thread.");
return;
}
_emptyURL.pop_front();
@@ -423,7 +420,7 @@ public:
/*if (_emptyURL.size() == 0 )
{
- std::cout << Util::logPrefix() << "No available childs, fork new one" << std::endl;
+ Log::info("No available childs, fork new one");
forkCounter++;
}*/
}
@@ -448,7 +445,7 @@ public:
#ifdef __linux
if (prctl(PR_SET_NAME, reinterpret_cast<unsigned long>("pipe_reader"), 0, 0, 0) != 0)
- std::cout << Util::logPrefix() << "Cannot set thread name :" << strerror(errno) << std::endl;
+ Log::error("Cannot set thread name.");
#endif
while (true)
@@ -462,13 +459,13 @@ public:
nBytes = Util::readFIFO(readerBroker, aBuffer, sizeof(aBuffer));
if (nBytes < 0)
{
- pStart = pEnd = NULL;
- std::cout << Util::logPrefix() << "Error reading message :" << strerror(errno) << std::endl;
+ pStart = pEnd = nullptr;
+ Log::error("Error reading message.");
continue;
}
pStart = aBuffer;
pEnd = aBuffer + nBytes;
- std::cout << Util::logPrefix() << "Broker readFIFO [" << std::string(pStart, nBytes) << "]" << std::endl;
+ Log::trace("Broker readFIFO: [" + std::string(pStart, nBytes) + "]");
}
}
@@ -510,14 +507,14 @@ static bool globalPreinit(const std::string &loSubPath)
handle = dlopen(fname.c_str(), RTLD_GLOBAL|RTLD_NOW);
if (!handle)
{
- std::cout << Util::logPrefix() << " Failed to load library :" << LIB_SOFFICEAPP << std::endl;
+ Log::warn("Failed to load " + std::string(LIB_SOFFICEAPP) + " library.");
return false;
}
preInit = (LokHookPreInit *)dlsym(handle, "lok_preinit");
if (!preInit)
{
- std::cout << Util::logPrefix() << " Failed to find lok_preinit hook in library :" << LIB_SOFFICEAPP << std::endl;
+ Log::warn("Failed to find lok_preinit hook in " + std::string(LIB_SOFFICEAPP) + " library.");
return false;
}
@@ -531,10 +528,9 @@ static int createLibreOfficeKit(bool sharePages, std::string loSubPath, Poco::UI
if (sharePages)
{
- Poco::UInt64 pid;
-
- std::cout << Util::logPrefix() + "Forking LibreOfficeKit" << std::endl;
+ Log::debug("Forking LibreOfficeKit.");
+ Poco::UInt64 pid;
if (!(pid = fork()))
{ // child
run_lok_main(loSubPath, childID, "");
@@ -553,7 +549,7 @@ static int createLibreOfficeKit(bool sharePages, std::string loSubPath, Poco::UI
if (mkfifo(pipe.c_str(), 0666) < 0)
{
- std::cout << Util::logPrefix() << "mkfifo :" << strerror(errno) << std::endl;
+ Log::error("Error: mkfifo failed.");
return -1;
}
@@ -561,15 +557,16 @@ static int createLibreOfficeKit(bool sharePages, std::string loSubPath, Poco::UI
args.push_back("--child=" + std::to_string(childID));
args.push_back("--pipe=" + pipe);
- std::cout << Util::logPrefix() + "Launching LibreOfficeKit: " + executable + " " + Poco::cat(std::string(" "), args.begin(), args.end()) << std::endl;
+ Log::info("Launching LibreOfficeKit: " + executable + " " +
+ Poco::cat(std::string(" "), args.begin(), args.end()));
ProcessHandle procChild = Process::launch(executable, args);
child = procChild.id();
- std::cout << Util::logPrefix() << "Launched kit process: " << child << std::endl;
+ Log::info("Launched kit process: " + std::to_string(child));
if ( ( nFIFOWriter = open(pipe.c_str(), O_WRONLY) ) < 0 )
{
- std::cout << Util::logPrefix() << "open: " << strerror(errno) << std::endl;
+ Log::error("Error: failed to open pipe [" + pipe + "] write only.");
return -1;
}
}
@@ -583,14 +580,15 @@ static int startupLibreOfficeKit(bool sharePages, int nLOKits,
{
Process::PID pId = -1;
- std::cout << Util::logPrefix() << "starting " << nLOKits << " LoKit instaces."
- << " Shared: " << sharePages << ", loSubPath: " << loSubPath
- << ", child: " << child << std::endl;
+ Log::info() << "Starting " << nLOKits << " LoKit instaces."
+ << " Shared: " << (sharePages ? "true" : "false")
+ << ", loSubPath: " << loSubPath
+ << ", child: " << child << Log::end;
for (int nCntr = nLOKits; nCntr; nCntr--)
{
if ( (pId = createLibreOfficeKit(sharePages, loSubPath, child)) < 0)
{
- std::cout << Util::logPrefix() << "startupLibreOfficeKit: " << strerror(errno) << std::endl;
+ Log::error("Error: failed to create LibreOfficeKit.");
break;
}
}
@@ -602,14 +600,14 @@ static int startupLibreOfficeKit(bool sharePages, int nLOKits,
int main(int argc, char** argv)
{
// Initialization
+ Log::initialize("brk");
+
std::string childRoot;
std::string loSubPath;
std::string sysTemplate;
std::string loTemplate;
int _numPreSpawnedChildren = 0;
- Log::initialize("brk");
-
for (int i = 0; i < argc; ++i)
{
char *cmd = argv[i];
@@ -648,37 +646,37 @@ int main(int argc, char** argv)
if (loSubPath.empty())
{
- std::cout << Util::logPrefix() << "--losubpath is empty" << std::endl;
+ Log::error("Error: --losubpath is empty");
exit(-1);
}
if (sysTemplate.empty())
{
- std::cout << Util::logPrefix() << "--systemplate is empty" << std::endl;
+ Log::error("Error: --losubpath is empty");
exit(-1);
}
if (loTemplate.empty())
{
- std::cout << Util::logPrefix() << "--lotemplate is empty" << std::endl;
+ Log::error("Error: --lotemplate is empty");
exit(-1);
}
if (childRoot.empty())
{
- std::cout << Util::logPrefix() << "--childroot is empty" << std::endl;
+ Log::error("Error: --childroot is empty");
exit(-1);
}
if ( !_numPreSpawnedChildren )
{
- std::cout << Util::logPrefix() << "--numprespawns is 0" << std::endl;
+ Log::error("Error: --numprespawns is 0");
exit(-1);
}
if ( (readerBroker = open(FIFO_FILE.c_str(), O_RDONLY) ) < 0 )
{
- std::cout << Util::logPrefix() << "pipe error: " << strerror(errno) << std::endl;
+ Log::error("Error: failed to open pipe [" + FIFO_FILE + "] read only. Exiting.");
exit(-1);
}
@@ -717,7 +715,7 @@ int main(int argc, char** argv)
// It is necessary to deploy loolkit process to chroot jail.
if (!File("loolkit").exists())
{
- std::cout << Util::logPrefix() << "loolkit does not exists" << std::endl;
+ Log::error("loolkit does not exists");
exit(-1);
}
File("loolkit").copyTo(Path(jailPath, "/usr/bin").toString());
@@ -740,31 +738,27 @@ int main(int argc, char** argv)
S_IFCHR | S_IRUSR | S_IWUSR | S_IRGRP | S_IWGRP | S_IROTH | S_IWOTH,
makedev(1, 8)) != 0)
{
- std::cout << Util::logPrefix() +
- "mknod(" + jailPath.toString() + "/dev/random) failed: " +
- strerror(errno) << std::endl;
+ Log::error("Error: mknod(" + jailPath.toString() + "/dev/random) failed.");
}
if (mknod((jailPath.toString() + "/dev/urandom").c_str(),
S_IFCHR | S_IRUSR | S_IWUSR | S_IRGRP | S_IWGRP | S_IROTH | S_IWOTH,
makedev(1, 9)) != 0)
{
- std::cout << Util::logPrefix() +
- "mknod(" + jailPath.toString() + "/dev/urandom) failed: " +
- strerror(errno) << std::endl;
+ Log::error("Error: mknod(" + jailPath.toString() + "/dev/urandom) failed.");
}
#endif
- std::cout << Util::logPrefix() << "loolbroker -> chroot(\"" + jailPath.toString() + "\")" << std::endl;
+ Log::info("loolbroker -> chroot(\"" + jailPath.toString() + "\")");
if (chroot(jailPath.toString().c_str()) == -1)
{
- std::cout << Util::logPrefix() << "chroot(\"" + jailPath.toString() + "\") failed: " + strerror(errno) << std::endl;
+ Log::error("Error: chroot(\"" + jailPath.toString() + "\") failed.");
exit(-1);
}
if (chdir("/") == -1)
{
- std::cout << Util::logPrefix() << std::string("chdir(\"/\") in jail failed: ") + strerror(errno) << std::endl;
+ Log::error("Error: chdir(\"/\") in jail failed.");
exit(-1);
}
@@ -778,7 +772,7 @@ int main(int argc, char** argv)
if (mkfifo(FIFO_BROKER.c_str(), 0666) == -1)
{
- std::cout << Util::logPrefix() << "Fail to create pipe FIFO " << strerror(errno) << std::endl;
+ Log::error("Error: Failed to create pipe FIFO.");
exit(-1);
}
@@ -786,13 +780,13 @@ int main(int argc, char** argv)
if ( startupLibreOfficeKit(sharePages, _numPreSpawnedChildren, loSubPath, _childId) < 0 )
{
- std::cout << Util::logPrefix() << "fail to create childs: " << strerror(errno) << std::endl;
+ Log::error("Error: failed to create children.");
exit(-1);
}
if ( (readerChild = open(FIFO_BROKER.c_str(), O_RDONLY) ) < 0 )
{
- std::cout << Util::logPrefix() << "pipe opened for reading: " << strerror(errno) << std::endl;
+ Log::error("Error: pipe opened for reading.");
exit(-1);
}
@@ -801,7 +795,7 @@ int main(int argc, char** argv)
aPipe.start(pipeHandler);
- std::cout << Util::logPrefix() << "loolwsd ready!" << std::endl;
+ Log::info("loolbroker ready!");
while (_childProcesses.size() > 0)
{
@@ -813,8 +807,8 @@ int main(int argc, char** argv)
{
if ((WIFEXITED(status) || WIFSIGNALED(status) || WTERMSIG(status) ) )
{
+ Log::error("Child [" + std::to_string(pid) + "] processes died.");
forkMutex.lock();
- std::cout << Util::logPrefix() << "One of our known child processes died :" << std::to_string(pid) << std::endl;
_childProcesses.erase(pid);
_cacheURL.clear();
_emptyURL.clear();
@@ -822,24 +816,24 @@ int main(int argc, char** argv)
}
if ( WCOREDUMP(status) )
- std::cout << Util::logPrefix() << "The child produced a core dump." << std::endl;
+ Log::error("Child [" + std::to_string(pid) + "] produced a core dump.");
if ( WIFSTOPPED(status) )
- std::cout << Util::logPrefix() << "The child process was stopped by delivery of a signal." << std::endl;
+ Log::error("Child [" + std::to_string(pid) + "] process was stopped by delivery of a signal.");
if ( WSTOPSIG(status) )
- std::cout << Util::logPrefix() << "The child process was stopped." << std::endl;
+ Log::error("Child [" + std::to_string(pid) + "] process was stopped.");
if ( WIFCONTINUED(status) )
- std::cout << Util::logPrefix() << "The child process was resumed." << std::endl;
+ Log::error("Child [" + std::to_string(pid) + "] process was resumed.");
}
else
{
- std::cout << Util::logPrefix() << "None of our known child processes died :" << std::to_string(pid) << std::endl;
+ Log::error("None of our known child processes died. PID: " + std::to_string(pid));
}
}
else if (pid < 0)
- std::cout << Util::logPrefix() << "Child error: " << strerror(errno) << std::endl;
+ Log::error("Error: Child error.");
if ( forkCounter > 0 )
{
@@ -847,7 +841,7 @@ int main(int argc, char** argv)
forkCounter -= 1;
if (createLibreOfficeKit(sharePages, loSubPath, _childId) < 0 )
- std::cout << Util::logPrefix() << "fork falied: " << strerror(errno) << std::endl;
+ Log::error("Error: fork falied.");
forkMutex.unlock();
}
@@ -863,11 +857,11 @@ int main(int argc, char** argv)
// Terminate child processes
for (auto i : _childProcesses)
{
- std::cout << Util::logPrefix() + "Requesting child process " + std::to_string(i.first) + " to terminate" << std::endl;
+ Log::info("Requesting child process " + std::to_string(i.first) + " to terminate.");
Process::requestTermination(i.first);
}
- std::cout << Util::logPrefix() << "loolbroker finished OK!" << std::endl;
+ Log::info("loolbroker finished OK!");
return 0;
}
diff --git a/loolwsd/LOOLKit.cpp b/loolwsd/LOOLKit.cpp
index 0cfeb14..b003bfb 100644
--- a/loolwsd/LOOLKit.cpp
+++ b/loolwsd/LOOLKit.cpp
@@ -264,8 +264,8 @@ public:
void run() override
{
#ifdef __linux
- if (prctl(PR_SET_NAME, reinterpret_cast<unsigned long>("queue_handler"), 0, 0, 0) != 0)
- Log::error(std::string("Cannot set thread name :") + strerror(errno));
+ if (prctl(PR_SET_NAME, reinterpret_cast<unsigned long>("queue_handler"), 0, 0, 0) != 0)
+ Log::error("Cannot set thread name.");
#endif
try
{
@@ -326,7 +326,7 @@ public:
{
#ifdef __linux
if (prctl(PR_SET_NAME, reinterpret_cast<unsigned long>("lokit_connection"), 0, 0, 0) != 0)
- Log::warn("Cannot set thread name: " + std::string(strerror(errno)));
+ Log::error("Cannot set thread name.");
#endif
try
{
@@ -419,7 +419,7 @@ void run_lok_main(const std::string &loSubPath, Poco::UInt64 _childId, const std
#ifdef __linux
if (prctl(PR_SET_NAME, reinterpret_cast<unsigned long>("libreofficekit"), 0, 0, 0) != 0)
- Log::warn("Cannot set thread name: " + std::string(strerror(errno)));
+ Log::error("Cannot set thread name.");
#endif
if (std::getenv("SLEEPFORDEBUGGER"))
@@ -448,15 +448,13 @@ void run_lok_main(const std::string &loSubPath, Poco::UInt64 _childId, const std
if ( (readerBroker = open(pipe.c_str(), O_RDONLY) ) < 0 )
{
- Log::error("Error: failed to open pipe [" + pipe + "] read only: " +
- std::string(strerror(errno)) + ". Exiting.");
+ Log::error("Error: failed to open pipe [" + pipe + "] read only.");
exit(-1);
}
if ( (writerBroker = open(LOKIT_BROKER.c_str(), O_WRONLY) ) < 0 )
{
- Log::error("Error: failed to open pipe [" + LOKIT_BROKER + "] write only: " +
- std::string(strerror(errno)) + ". Exiting.");
+ Log::error("Error: failed to open pipe [" + LOKIT_BROKER + "] write only.");
exit(-1);
}
@@ -484,7 +482,7 @@ void run_lok_main(const std::string &loSubPath, Poco::UInt64 _childId, const std
if (nBytes < 0)
{
pStart = pEnd = nullptr;
- Log::warn("Error reading message from FIFO: " + std::string(strerror(errno)));
+ Log::error("Error reading message from pipe [" + pipe + "].");
continue;
}
pStart = aBuffer;
diff --git a/loolwsd/LOOLSession.cpp b/loolwsd/LOOLSession.cpp
index b43908c..68d8e42 100644
--- a/loolwsd/LOOLSession.cpp
+++ b/loolwsd/LOOLSession.cpp
@@ -113,9 +113,12 @@ LOOLSession::~LOOLSession()
void LOOLSession::sendTextFrame(const std::string& text)
{
if (!_ws)
- Log::error("No socket to send to.");
+ {
+ Log::error("Error: No socket to send to.");
+ return;
+ }
else
- Log::debug(_kindString + ",Send," + getAbbreviatedMessage(text.c_str(), text.size()));
+ Log::trace(_kindString + ",Send," + getAbbreviatedMessage(text.c_str(), text.size()));
std::unique_lock<std::mutex> lock(_mutex);
@@ -125,21 +128,22 @@ void LOOLSession::sendTextFrame(const std::string& text)
void LOOLSession::sendBinaryFrame(const char *buffer, int length)
{
if (!_ws)
- Log::error("No socket to send to.");
+ {
+ Log::error("Error: No socket to send to.");
+ return;
+ }
else
- Log::debug(_kindString + ",Send," + std::to_string(length) + " bytes");
+ Log::trace(_kindString + ",Send," + std::to_string(length) + " bytes");
std::unique_lock<std::mutex> lock(_mutex);
if (length > 1000)
{
std::string nextmessage = "nextmessage: size=" + std::to_string(length);
- if (_ws)
- _ws->sendFrame(nextmessage.data(), nextmessage.size());
+ _ws->sendFrame(nextmessage.data(), nextmessage.size());
}
- if (_ws)
- _ws->sendFrame(buffer, length, WebSocket::FRAME_BINARY);
+ _ws->sendFrame(buffer, length, WebSocket::FRAME_BINARY);
}
void LOOLSession::parseDocOptions(const StringTokenizer& tokens, int& part, std::string& timestamp)
diff --git a/loolwsd/LOOLWSD.cpp b/loolwsd/LOOLWSD.cpp
index d543c32..2c9050c 100644
--- a/loolwsd/LOOLWSD.cpp
+++ b/loolwsd/LOOLWSD.cpp
@@ -166,20 +166,20 @@ namespace
caps = cap_get_proc();
if (caps == NULL)
{
- Log::error(std::string("cap_get_proc() failed: ") + strerror(errno));
+ Log::error("cap_get_proc() failed.");
exit(1);
}
if (cap_set_flag(caps, CAP_EFFECTIVE, sizeof(cap_list)/sizeof(cap_list[0]), cap_list, CAP_CLEAR) == -1 ||
cap_set_flag(caps, CAP_PERMITTED, sizeof(cap_list)/sizeof(cap_list[0]), cap_list, CAP_CLEAR) == -1)
{
- Log::error(std::string("cap_set_flag() failed: ") + strerror(errno));
+ Log::error("cap_set_flag() failed.");
exit(1);
}
if (cap_set_proc(caps) == -1)
{
- Log::error(std::string("cap_set_proc() failed: ") + strerror(errno));
+ Log::error("cap_set_proc() failed.");
exit(1);
}
@@ -198,7 +198,7 @@ namespace
// to do chroot().
if (setuid(getuid()) != 0)
{
- Log::error(std::string("setuid() failed: ") + strerror(errno));
+ Log::error("setuid() failed.");
}
}
#if ENABLE_DEBUG
@@ -222,7 +222,7 @@ namespace
}
if (setuid(LOOLWSD::uid) != 0)
{
- Log::error(std::string("setuid() failed: ") + strerror(errno));
+ Log::error("setuid() failed.");
}
}
#endif
@@ -246,7 +246,7 @@ public:
{
#ifdef __linux
if (prctl(PR_SET_NAME, reinterpret_cast<unsigned long>("queue_handler"), 0, 0, 0) != 0)
- std::cout << Util::logPrefix() << "Cannot set thread name :" << strerror(errno) << std::endl;
+ Log::error("Cannot set thread name.");
#endif
while (true)
@@ -319,7 +319,7 @@ public:
thread_name = "client_socket";
if (prctl(PR_SET_NAME, reinterpret_cast<unsigned long>(thread_name.c_str()), 0, 0, 0) != 0)
- std::cout << Util::logPrefix() << "Cannot set thread name :" << strerror(errno) << std::endl;
+ Log::error("Cannot set thread name.");
#endif
if(!(request.find("Upgrade") != request.end() && Poco::icompare(request["Upgrade"], "websocket") == 0))
@@ -842,9 +842,8 @@ int LOOLWSD::createBroker()
std::string executable = Path(Application::instance().commandPath()).parent().toString() + "loolbroker";
- const auto msg = Util::logPrefix() + "Launching broker: " + executable + " "
- + Poco::cat(std::string(" "), args.begin(), args.end());
- Log::info(msg);
+ Log::info("Launching Broker: " + executable + " " +
+ Poco::cat(std::string(" "), args.begin(), args.end()));
ProcessHandle child = Process::launch(executable, args);
@@ -876,7 +875,7 @@ int LOOLWSD::main(const std::vector<std::string>& /*args*/)
setSignals(false);
#endif
- Log::initialize("brk");
+ Log::initialize("wsd");
if (access(cache.c_str(), R_OK | W_OK | X_OK) != 0)
{
@@ -948,7 +947,7 @@ int LOOLWSD::main(const std::vector<std::string>& /*args*/)
if ( (writerBroker = open(FIFO_FILE.c_str(), O_WRONLY) ) < 0 )
{
- std::cout << Util::logPrefix() << "Pipe opened for writing" << strerror(errno) << std::endl;
+ Log::error("Error: failed to open pipe [" + FIFO_FILE + "] write only.");
return Application::EXIT_UNAVAILABLE;
}
@@ -971,29 +970,29 @@ int LOOLWSD::main(const std::vector<std::string>& /*args*/)
{
if ((WIFEXITED(status) || WIFSIGNALED(status) || WTERMSIG(status) ) )
{
- std::cout << Util::logPrefix() << "One of our known child processes died :" << std::to_string(pid) << std::endl;
+ Log::error("Child [" + std::to_string(pid) + "] processes died.");
MasterProcessSession::_childProcesses.erase(pid);
}
if ( WCOREDUMP(status) )
- std::cout << Util::logPrefix() << "The child produced a core dump." << std::endl;
+ Log::error("Child [" + std::to_string(pid) + "] produced a core dump.");
if ( WIFSTOPPED(status) )
- std::cout << Util::logPrefix() << "The child process was stopped by delivery of a signal." << std::endl;
+ Log::error("Child [" + std::to_string(pid) + "] process was stopped by delivery of a signal.");
if ( WSTOPSIG(status) )
- std::cout << Util::logPrefix() << "The child process was stopped." << std::endl;
+ Log::error("Child [" + std::to_string(pid) + "] process was stopped.");
if ( WIFCONTINUED(status) )
- std::cout << Util::logPrefix() << "The child process was resumed." << std::endl;
+ Log::error("Child [" + std::to_string(pid) + "] process was resumed.");
}
else
{
- std::cout << Util::logPrefix() << "None of our known child processes died :" << std::to_string(pid) << std::endl;
+ Log::error("None of our known child processes died. PID: " + std::to_string(pid));
}
}
else if (pid < 0)
- std::cout << Util::logPrefix() << "Child error: " << strerror(errno) << std::endl;
+ Log::error("Error: Child error.");
++timeoutCounter;
if (timeoutCounter == INTERVAL_PROBES)
diff --git a/loolwsd/MasterProcessSession.cpp b/loolwsd/MasterProcessSession.cpp
index 2428b82..c9ab731 100644
--- a/loolwsd/MasterProcessSession.cpp
+++ b/loolwsd/MasterProcessSession.cpp
@@ -71,7 +71,7 @@ MasterProcessSession::~MasterProcessSession()
bool MasterProcessSession::handleInput(const char *buffer, int length)
{
- Log::info(_kindString + ",Recv," + getAbbreviatedMessage(buffer, length));
+ Log::trace(_kindString + ",Recv," + getAbbreviatedMessage(buffer, length));
std::string firstLine = getFirstLine(buffer, length);
StringTokenizer tokens(firstLine, " ", StringTokenizer::TOK_IGNORE_EMPTY | StringTokenizer::TOK_TRIM);
@@ -622,8 +622,7 @@ void MasterProcessSession::dispatchChild()
if (!File(aDstFile).exists() && link(aSrcFile.toString().c_str(), aDstFile.toString().c_str()) == -1)
{
// Failed
- Log::error(
- "link(\"" + aSrcFile.toString() + "\",\"" + aDstFile.toString() + "\") failed: " + strerror(errno) );
+ Log::error("link(\"" + aSrcFile.toString() + "\",\"" + aDstFile.toString() + "\") failed.");
}
#endif
@@ -632,31 +631,31 @@ void MasterProcessSession::dispatchChild()
//fallback
if (!File(aDstFile).exists())
{
- Log::info(Util::logPrefix() + "Copying " + aSrcFile.toString() + " to " + aDstFile.toString());
+ Log::info("Copying " + aSrcFile.toString() + " to " + aDstFile.toString());
File(aSrcFile).copyTo(aDstFile.toString());
}
}
catch (Exception& exc)
{
- Log::error(
- "copyTo(\"" + aSrcFile.toString() + "\",\"" + aDstFile.toString() + "\") failed: " + exc.displayText());
+ Log::error("copyTo(\"" + aSrcFile.toString() + "\",\"" + aDstFile.toString() + "\") failed: " + exc.displayText());
}
}
_peer = childSession;
childSession->_peer = shared_from_this();
- std::string loadRequest = "load" + (_loadPart >= 0 ? " part=" + std::to_string(_loadPart) : "") + " url=" + _docURL + (!_docOptions.empty() ? " options=" + _docOptions : "");
+ const std::string loadRequest = "load" + (_loadPart >= 0 ? " part=" + std::to_string(_loadPart) : "")
+ + " url=" + _docURL + (!_docOptions.empty() ? " options=" + _docOptions : "");
forwardToPeer(loadRequest.c_str(), loadRequest.size());
}
void MasterProcessSession::forwardToPeer(const char *buffer, int length)
{
- Log::info(_kindString + ",forwardToPeer," + getAbbreviatedMessage(buffer, length));
+ Log::trace(_kindString + ",forwardToPeer," + getAbbreviatedMessage(buffer, length));
auto peer = _peer.lock();
if (!peer)
{
- Log::error("no peer to forward to");
+ Log::error("Error: no peer to forward to.");
return;
}
peer->sendBinaryFrame(buffer, length);
diff --git a/loolwsd/Util.cpp b/loolwsd/Util.cpp
index c6ee312..6edb162 100644
--- a/loolwsd/Util.cpp
+++ b/loolwsd/Util.cpp
@@ -30,6 +30,7 @@
#include <Poco/Thread.h>
#include <Poco/Util/Application.h>
#include <Poco/Environment.h>
+#include <Poco/ConsoleChannel.h>
#include "Util.hpp"
#include "Png.hpp"
@@ -72,12 +73,18 @@ namespace rng
namespace Log
{
- static std::string binname;
+ static std::string SourceName;
+ static std::string SourceId;
void initialize(const std::string& name)
{
- binname = name;
- auto& logger = Poco::Logger::get(name);
+ SourceName = name;
+ std::ostringstream oss;
+ oss << SourceName << '-'
+ << std::setw(5) << std::setfill('0') << Poco::Process::id();
+ SourceId = oss.str();
+
+ auto& logger = Poco::Logger::create(SourceName, new Poco::ColorConsoleChannel(), Poco::Message::PRIO_INFORMATION);
// Configure the logger.
// TODO: This should come from a file.
@@ -92,18 +99,23 @@ namespace Log
{
}
- logger.information("Initializing " + name);
- logger.information("Log level is " + logger.getLevel());
+ info("Initializing " + name);
+ info("Log level is [" + std::to_string(logger.getLevel()) + "].");
}
Poco::Logger& logger()
{
- return Poco::Logger::get(binname);
+ return Poco::Logger::get(SourceName);
+ }
+
+ void trace(const std::string& msg)
+ {
+ logger().trace(Util::logPrefix() + msg);
}
void debug(const std::string& msg)
{
- return logger().debug(Util::logPrefix() + msg);
+ logger().debug(Util::logPrefix() + msg);
}
void info(const std::string& msg)
@@ -113,12 +125,12 @@ namespace Log
void warn(const std::string& msg)
{
- return logger().warning(Util::logPrefix() + msg);
+ logger().warning(Util::logPrefix() + msg);
}
void error(const std::string& msg)
{
- return logger().error(Util::logPrefix() + msg);
+ logger().error(Util::logPrefix() + msg + " (" + strerror(errno) + ").");
}
}
@@ -139,10 +151,11 @@ namespace Util
usec %= (one_s);
std::ostringstream stream;
- stream << Log::binname << ',' << Poco::Process::id() << ',' << std::setw(2) << std::setfill('0')
- << (Poco::Thread::current() ? Poco::Thread::current()->id() : 0) << ',' << std::setw(2) << ','
- << hours << ':' << std::setw(2) << minutes << ':' << std::setw(2) << seconds << "." << std::setw(6) << usec
- << ',';
+ stream << Log::SourceId << '-' << std::setw(2) << std::setfill('0')
+ << (Poco::Thread::current() ? Poco::Thread::current()->id() : 0) << ','
+ << std::setw(2) << hours << ':' << std::setw(2) << minutes << ':'
+ << std::setw(2) << seconds << "." << std::setw(6) << usec
+ << ", ";
return stream.str();
}
diff --git a/loolwsd/Util.hpp b/loolwsd/Util.hpp
index aba885b..e57c100 100644
--- a/loolwsd/Util.hpp
+++ b/loolwsd/Util.hpp
@@ -11,6 +11,7 @@
#define INCLUDED_UTIL_HPP
#include <string>
+#include <sstream>
#include <Poco/Net/WebSocket.h>
#include <Poco/Logger.h>
@@ -51,10 +52,89 @@ namespace Log
void initialize(const std::string& name);
Poco::Logger& logger();
+ 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);
+
+ // The following is to write streaming logs.
+ // Log::info() << "Value: 0x" << std::hex << value
+ // << ", pointer: " << this << Log::end;
+
+ static const struct _end_marker
+ {
+ } end;
+
+ class StreamLogger
+ {
+ public:
+ StreamLogger(std::function<void(const std::string&)> func)
+ : _func(func)
+ {
+ }
+
+ void flush() const
+ {
+ _func(Stream.str());
+ }
+
+ std::ostringstream Stream;
+
+ private:
+ std::function<void(const std::string&)> _func;
+ };
+
+ inline
+ StreamLogger trace()
+ {
+ return StreamLogger([](const std::string& msg) { trace(msg);});
+ }
+
+ inline
+ StreamLogger debug()
+ {
+ return StreamLogger([](const std::string& msg) { debug(msg);});
+ }
+
+ inline
+ StreamLogger info()
+ {
+ return StreamLogger([](const std::string& msg) { info(msg);});
+ }
+
+ inline
+ StreamLogger warn()
+ {
+ return StreamLogger([](const std::string& msg) { warn(msg);});
+ }
+
+ inline
+ StreamLogger error()
+ {
+ return StreamLogger([](const std::string& msg) { error(msg);});
+ }
+
+ template <typename U>
+ StreamLogger& operator <<(StreamLogger& lhs, const U& rhs)
+ {
+ lhs.Stream << rhs;
+ return lhs;
+ }
+
+ template <typename U>
+ StreamLogger& operator <<(StreamLogger&& lhs, U&& rhs)
+ {
+ lhs.Stream << rhs;
+ return lhs;
+ }
+
+ inline
+ void operator <<(StreamLogger& lhs, const _end_marker&)
+ {
+ (void)end;
+ lhs.flush();
+ }
}
#endif
More information about the Libreoffice-commits
mailing list