[Libreoffice-commits] online.git: common/Log.hpp common/Protocol.hpp common/Util.cpp net/Socket.hpp test/countloolkits.hpp test/helpers.hpp test/httpcrashtest.cpp test/httpwserror.cpp test/httpwstest.cpp test/integration-http-server.cpp test/TileCacheTests.cpp wsd/AdminModel.cpp wsd/TileCache.cpp
Ashod Nakashian
ashod.nakashian at collabora.co.uk
Sun Feb 11 18:21:34 UTC 2018
common/Log.hpp | 25 +++++
common/Protocol.hpp | 3
common/Util.cpp | 11 +-
net/Socket.hpp | 23 ++---
test/TileCacheTests.cpp | 4
test/countloolkits.hpp | 13 +--
test/helpers.hpp | 141 ++++++++++++++++++++------------
test/httpcrashtest.cpp | 41 +++++----
test/httpwserror.cpp | 4
test/httpwstest.cpp | 168 ++++++++++++++++++++-------------------
test/integration-http-server.cpp | 4
wsd/AdminModel.cpp | 6 -
wsd/TileCache.cpp | 6 -
13 files changed, 268 insertions(+), 181 deletions(-)
New commits:
commit 7be98efd93be513b34f7d0a81d30a777902e90de
Author: Ashod Nakashian <ashod.nakashian at collabora.co.uk>
Date: Mon Jan 22 09:11:43 2018 -0500
ut: log timestamp to track timeouts better
And improve the logging support in unit-tests to
help troubleshoot issues faster and more accurately.
Also makes the code more readable (hopefully).
Change-Id: I4f8aafb5245e2f774b03231591a74544f9ec84aa
Reviewed-on: https://gerrit.libreoffice.org/48645
Reviewed-by: Ashod Nakashian <ashnakash at gmail.com>
Tested-by: Ashod Nakashian <ashnakash at gmail.com>
diff --git a/common/Log.hpp b/common/Log.hpp
index a3e4a9ae..bb5a6155 100644
--- a/common/Log.hpp
+++ b/common/Log.hpp
@@ -14,6 +14,7 @@
#include <unistd.h>
#include <functional>
+#include <thread>
#include <sstream>
#include <string>
@@ -187,6 +188,30 @@ namespace Log
(void)end;
lhs.flush();
}
+
+ /// Dump the invalid id as 0, otherwise dump in hex.
+ inline std::string to_string(const std::thread::id& id)
+ {
+ if (id != std::thread::id())
+ {
+ std::ostringstream os;
+ os << std::hex << "0x" << id << std::dec;
+ return os.str();
+ }
+
+ return "0";
+ }
+
+ inline StreamLogger& operator<<(StreamLogger& lhs, const std::thread::id& rhs)
+ {
+ if (lhs.enabled())
+ {
+ lhs._stream << Log::to_string(rhs);
+ }
+
+ return lhs;
+ }
+
}
#define LOG_BODY_(PRIO, LVL, X) Poco::Message m_(l_.name(), "", Poco::Message::PRIO_##PRIO); char b_[1024]; std::ostringstream oss_(Log::prefix(b_, LVL, false), std::ostringstream::ate); oss_ << std::boolalpha << X << "| " << __FILE__ << ':' << __LINE__; m_.setText(oss_.str()); l_.log(m_);
diff --git a/common/Protocol.hpp b/common/Protocol.hpp
index 61f35b71..61e16d31 100644
--- a/common/Protocol.hpp
+++ b/common/Protocol.hpp
@@ -12,6 +12,7 @@
#include <cstdint>
#include <cstring>
+#include <iomanip>
#include <map>
#include <sstream>
#include <string>
@@ -320,7 +321,7 @@ namespace LOOLProtocol
result << Poco::format("%#x", flags);
break;
}
- result << " " << length << " bytes";
+ result << " " << std::setw(3) << length << " bytes";
if (length > 0 &&
((flags & Poco::Net::WebSocket::FRAME_OP_BITMASK) == Poco::Net::WebSocket::FRAME_OP_TEXT ||
diff --git a/common/Util.cpp b/common/Util.cpp
index 7605c5a3..7f320d38 100644
--- a/common/Util.cpp
+++ b/common/Util.cpp
@@ -453,13 +453,12 @@ namespace Util
strncpy(ThreadName, s.c_str(), 31);
ThreadName[31] = '\0';
if (prctl(PR_SET_NAME, reinterpret_cast<unsigned long>(s.c_str()), 0, 0, 0) != 0)
- LOG_SYS("Cannot set thread name of " << getThreadId() << " (0x" <<
- std::hex << std::this_thread::get_id() <<
- std::dec << ") to [" << s << "].");
+ LOG_SYS("Cannot set thread name of " << getThreadId() << " (" <<
+ std::this_thread::get_id() << ") to [" << s << "].");
else
- LOG_INF("Thread " << getThreadId() << " (0x" <<
- std::hex << std::this_thread::get_id() <<
- std::dec << ") is now called [" << s << "].");
+ LOG_INF("Thread " << getThreadId() << " (" <<
+ std::this_thread::get_id() <<
+ ") is now called [" << s << "].");
}
const char *getThreadName()
diff --git a/net/Socket.hpp b/net/Socket.hpp
index 7e5035b4..bec3744d 100644
--- a/net/Socket.hpp
+++ b/net/Socket.hpp
@@ -242,8 +242,8 @@ public:
{
if (id != _owner)
{
- LOG_DBG("#" << _fd << " Thread affinity set to 0x" << std::hex <<
- id << " (was 0x" << _owner << ")." << std::dec);
+ LOG_DBG("#" << _fd << " Thread affinity set to " << Log::to_string(id) <<
+ " (was " << Log::to_string(_owner) << ").");
_owner = id;
}
}
@@ -261,9 +261,9 @@ public:
// 0 owner means detached and can be invoked by any thread.
const bool sameThread = (_owner == std::thread::id(0) || std::this_thread::get_id() == _owner);
if (!sameThread)
- LOG_ERR("#" << _fd << " Invoked from foreign thread. Expected: 0x" << std::hex <<
- _owner << " but called from 0x" << std::this_thread::get_id() << " (" <<
- std::dec << Util::getThreadId() << ").");
+ LOG_ERR("#" << _fd << " Invoked from foreign thread. Expected: " <<
+ Log::to_string(_owner) << " but called from " <<
+ std::this_thread::get_id() << " (" << Util::getThreadId() << ").");
assert(sameThread);
}
@@ -283,8 +283,7 @@ protected:
setNoDelay();
_sendBufferSize = DefaultSendBufferSize;
_owner = std::this_thread::get_id();
- LOG_DBG("#" << _fd << " Thread affinity set to 0x" << std::hex <<
- _owner << "." << std::dec);
+ LOG_DBG("#" << _fd << " Thread affinity set to " << _owner << ".");
#if ENABLE_DEBUG
if (std::getenv("LOOL_ZERO_BUFFER_SIZE"))
@@ -381,9 +380,9 @@ public:
// 0 owner means detached and can be invoked by any thread.
const bool sameThread = (!isAlive() || _owner == std::thread::id(0) || std::this_thread::get_id() == _owner);
if (!sameThread)
- LOG_ERR("Incorrect thread affinity for " << _name << ". Expected: 0x" << std::hex <<
- _owner << " (" << std::dec << Util::getThreadId() << ") but called from 0x" <<
- std::hex << std::this_thread::get_id() << std::dec << ", stop: " << _stop);
+ LOG_ERR("Incorrect thread affinity for " << _name << ". Expected: " <<
+ Log::to_string(_owner) << " (" << Util::getThreadId() <<
+ ") but called from " << std::this_thread::get_id() << ", stop: " << _stop);
assert(_stop || sameThread);
}
@@ -615,8 +614,8 @@ private:
LOG_INF("Starting polling thread [" << _name << "].");
_owner = std::this_thread::get_id();
- LOG_DBG("Thread affinity of " << _name << " set to 0x" <<
- std::hex << _owner << "." << std::dec);
+ LOG_DBG("Thread affinity of " << _name << " set to " <<
+ Log::to_string(_owner) << ".");
// Invoke the virtual implementation.
pollingThread();
diff --git a/test/TileCacheTests.cpp b/test/TileCacheTests.cpp
index 2c22da3a..e770e1ff 100644
--- a/test/TileCacheTests.cpp
+++ b/test/TileCacheTests.cpp
@@ -143,12 +143,16 @@ public:
void setUp()
{
+ resetTestStartTime();
testCountHowManyLoolkits();
+ resetTestStartTime();
}
void tearDown()
{
+ resetTestStartTime();
testNoExtraLoolKitsLeft();
+ resetTestStartTime();
}
};
diff --git a/test/countloolkits.hpp b/test/countloolkits.hpp
index 4b157b9a..90b89e12 100644
--- a/test/countloolkits.hpp
+++ b/test/countloolkits.hpp
@@ -22,10 +22,12 @@
#include <Common.hpp>
#include "test.hpp"
+#include "helpers.hpp"
static int countLoolKitProcesses(const int expected)
{
- std::cerr << "Waiting until loolkit processes are exactly " << expected << ". Loolkits: ";
+ const auto testname = "countLoolKitProcesses ";
+ TST_LOG_BEGIN("Waiting until loolkit processes are exactly " << expected << ". Loolkits: ");
// This does not need to depend on any constant from Common.hpp.
// The shorter the better (the quicker the test runs).
@@ -36,7 +38,7 @@ static int countLoolKitProcesses(const int expected)
int count = getLoolKitProcessCount();
for (size_t i = 0; i < repeat; ++i)
{
- std::cerr << count << ' ';
+ TST_LOG_APPEND(count << ' ');
if (count == expected)
{
break;
@@ -54,10 +56,10 @@ static int countLoolKitProcesses(const int expected)
}
}
- std::cerr << std::endl;
+ TST_LOG_END;
if (expected != count)
{
- std::cerr << "Found " << count << " LoKit processes but was expecting " << expected << "." << std::endl;
+ TST_LOG("Found " << count << " LoKit processes but was expecting " << expected << ".");
}
return count;
@@ -84,13 +86,14 @@ static void testCountHowManyLoolkits()
static void testNoExtraLoolKitsLeft()
{
+ const char* testname = "noExtraLoolKitsLeft ";
const int countNow = countLoolKitProcesses(InitialLoolKitCount);
CPPUNIT_ASSERT_EQUAL(InitialLoolKitCount, countNow);
const auto duration = (std::chrono::steady_clock::now() - TestStartTime);
const std::chrono::milliseconds::rep durationMs = std::chrono::duration_cast<std::chrono::milliseconds>(duration).count();
- std::cout << " (" << durationMs << " ms)";
+ TST_LOG(" (" << durationMs << " ms)");
}
#endif
diff --git a/test/helpers.hpp b/test/helpers.hpp
index 68038a8d..67d5d97b 100644
--- a/test/helpers.hpp
+++ b/test/helpers.hpp
@@ -37,12 +37,41 @@
#error TDOC must be defined (see Makefile.am)
#endif
+// Logging in unit-tests go to cerr, for now at least.
+#define TST_LOG_NAME_BEGIN(NAME, X) do { std::cerr << NAME << "(@" << helpers::timeSinceTestStartMs() << "ms) " << X; } while (false)
+#define TST_LOG_BEGIN(X) TST_LOG_NAME_BEGIN(testname, X)
+#define TST_LOG_APPEND(X) do { std::cerr << X; } while (false)
+#define TST_LOG_END do { std::cerr << "| " << __FILE__ << ':' << __LINE__ << std::endl; } while (false)
+#define TST_LOG_NAME(NAME, X) TST_LOG_NAME_BEGIN(NAME, X); TST_LOG_END
+#define TST_LOG(X) TST_LOG_NAME(testname, X)
+
/// Common helper testing functions.
/// Avoid the temptation to reuse from LOOL code!
/// These are supposed to be testing the latter.
namespace helpers
{
inline
+std::chrono::time_point<std::chrono::steady_clock>& getTestStartTime()
+{
+ static auto TestStartTime = std::chrono::steady_clock::now();
+
+ return TestStartTime;
+}
+
+inline
+void resetTestStartTime()
+{
+ getTestStartTime() = std::chrono::steady_clock::now();
+}
+
+inline
+size_t timeSinceTestStartMs()
+{
+ return std::chrono::duration_cast<std::chrono::milliseconds>(
+ std::chrono::steady_clock::now() - getTestStartTime()).count();
+}
+
+inline
std::vector<char> genRandomData(const size_t size)
{
std::vector<char> v(size);
@@ -101,21 +130,22 @@ std::vector<char> readDataFromFile(std::unique_ptr<std::fstream>& file)
inline
void getDocumentPathAndURL(const std::string& docFilename, std::string& documentPath, std::string& documentURL, std::string prefix)
{
+ const auto testname = prefix;
std::replace(prefix.begin(), prefix.end(), ' ', '_');
documentPath = FileUtil::getTempFilePath(TDOC, docFilename, prefix);
std::string encodedUri;
Poco::URI::encode("file://" + Poco::Path(documentPath).makeAbsolute().toString(), ":/?", encodedUri);
documentURL = "lool/" + encodedUri + "/ws";
- std::cerr << "Test file: " << documentPath << std::endl;
+ TST_LOG("Test file: " << documentPath);
}
inline
-void sendTextFrame(LOOLWebSocket& socket, const std::string& string, const std::string& name = "")
+void sendTextFrame(LOOLWebSocket& socket, const std::string& string, const std::string& testname = "")
{
#ifndef FUZZER
- std::cerr << name << "Sending " << string.size() << " bytes: " << LOOLProtocol::getAbbreviatedMessage(string) << std::endl;
+ TST_LOG("Sending " << string.size() << " bytes: " << LOOLProtocol::getAbbreviatedMessage(string));
#else
- (void) name;
+ (void) testname;
#endif
socket.sendFrame(string.data(), string.size());
}
@@ -165,7 +195,7 @@ int getErrorCode(LOOLWebSocket& ws, std::string& message, const std::string& tes
do
{
bytes = ws.receiveFrame(buffer.begin(), READ_BUFFER_SIZE, flags);
- std::cerr << testname << "Got " << LOOLProtocol::getAbbreviatedFrameDump(buffer.begin(), bytes, flags) << std::endl;
+ TST_LOG("Got " << LOOLProtocol::getAbbreviatedFrameDump(buffer.begin(), bytes, flags));
std::this_thread::sleep_for(std::chrono::milliseconds(POLL_TIMEOUT_MS));
}
while (bytes > 0 && (flags & Poco::Net::WebSocket::FRAME_OP_BITMASK) != Poco::Net::WebSocket::FRAME_OP_CLOSE);
@@ -187,9 +217,8 @@ int getErrorCode(const std::shared_ptr<LOOLWebSocket>& ws, std::string& message,
}
inline
-std::vector<char> getResponseMessage(LOOLWebSocket& ws, const std::string& prefix, std::string name = "", const size_t timeoutMs = 10000)
+std::vector<char> getResponseMessage(LOOLWebSocket& ws, const std::string& prefix, const std::string& testname = "", const size_t timeoutMs = 10000)
{
- name = name + '[' + prefix + "] ";
try
{
int flags = 0;
@@ -205,19 +234,20 @@ std::vector<char> getResponseMessage(LOOLWebSocket& ws, const std::string& prefi
{
if (timedout)
{
- std::cerr << std::endl;
+ TST_LOG_END;
timedout = false;
}
response.resize(READ_BUFFER_SIZE * 8);
int bytes = ws.receiveFrame(response.data(), response.size(), flags);
response.resize(std::max(bytes, 0));
- std::cerr << name << "Got " << LOOLProtocol::getAbbreviatedFrameDump(response.data(), bytes, flags) << std::endl;
const auto message = LOOLProtocol::getFirstLine(response);
if (bytes > 0 && (flags & Poco::Net::WebSocket::FRAME_OP_BITMASK) != Poco::Net::WebSocket::FRAME_OP_CLOSE)
{
if (LOOLProtocol::matchPrefix(prefix, message))
{
+ TST_LOG("[" << prefix << "] Matched " <<
+ LOOLProtocol::getAbbreviatedFrameDump(response.data(), bytes, flags));
return response;
}
}
@@ -239,18 +269,19 @@ std::vector<char> getResponseMessage(LOOLWebSocket& ws, const std::string& prefi
throw std::runtime_error(message);
}
- std::cerr << name << "Ignored: " << message << std::endl;
+ TST_LOG("[" << prefix << "] Ignored " <<
+ LOOLProtocol::getAbbreviatedFrameDump(response.data(), bytes, flags));
}
}
else
{
if (!timedout)
{
- std::cerr << name << "Timeout ";
+ TST_LOG_BEGIN("Timeout (" << (retries > 1 ? "retrying" : "giving up") << ") ");
}
else
{
- std::cerr << retries << ' ';
+ TST_LOG_APPEND(retries << ' ');
}
--retries;
@@ -261,59 +292,60 @@ std::vector<char> getResponseMessage(LOOLWebSocket& ws, const std::string& prefi
if (timedout)
{
- std::cerr << std::endl;
+ TST_LOG_END;
}
}
catch (const Poco::Net::WebSocketException& exc)
{
- std::cerr << std::endl << exc.message();
+ TST_LOG_END;
+ TST_LOG(exc.message());
}
return std::vector<char>();
}
inline
-std::vector<char> getResponseMessage(const std::shared_ptr<LOOLWebSocket>& ws, const std::string& prefix, const std::string& name = "", const size_t timeoutMs = 10000)
+std::vector<char> getResponseMessage(const std::shared_ptr<LOOLWebSocket>& ws, const std::string& prefix, const std::string& testname = "", const size_t timeoutMs = 10000)
{
- return getResponseMessage(*ws, prefix, name, timeoutMs);
+ return getResponseMessage(*ws, prefix, testname, timeoutMs);
}
template <typename T>
-std::string getResponseString(T& ws, const std::string& prefix, const std::string& name = "", const size_t timeoutMs = 10000)
+std::string getResponseString(T& ws, const std::string& prefix, const std::string& testname = "", const size_t timeoutMs = 10000)
{
- const auto response = getResponseMessage(ws, prefix, name, timeoutMs);
+ const auto response = getResponseMessage(ws, prefix, testname, timeoutMs);
return std::string(response.data(), response.size());
}
template <typename T>
-std::string assertResponseString(T& ws, const std::string& prefix, const std::string name = "")
+std::string assertResponseString(T& ws, const std::string& prefix, const std::string testname = "")
{
- const auto res = getResponseString(ws, prefix, name);
+ const auto res = getResponseString(ws, prefix, testname);
CPPUNIT_ASSERT_EQUAL(prefix, res.substr(0, prefix.length()));
return res;
}
/// Assert that we don't get a response with the given prefix.
template <typename T>
-std::string assertNotInResponse(T& ws, const std::string& prefix, const std::string name = "")
+std::string assertNotInResponse(T& ws, const std::string& prefix, const std::string testname = "")
{
- const auto res = getResponseString(ws, prefix, name, 1000);
- CPPUNIT_ASSERT_MESSAGE(name + "Did not expect getting message [" + res + "].", res.empty());
+ const auto res = getResponseString(ws, prefix, testname, 1000);
+ CPPUNIT_ASSERT_MESSAGE(testname + "Did not expect getting message [" + res + "].", res.empty());
return res;
}
inline
-bool isDocumentLoaded(LOOLWebSocket& ws, const std::string& name = "", bool isView = true)
+bool isDocumentLoaded(LOOLWebSocket& ws, const std::string& testname = "", bool isView = true)
{
const std::string prefix = isView ? "status:" : "statusindicatorfinish:";
- const auto message = getResponseString(ws, prefix, name);
+ const auto message = getResponseString(ws, prefix, testname);
return LOOLProtocol::matchPrefix(prefix, message);
}
inline
-bool isDocumentLoaded(std::shared_ptr<LOOLWebSocket>& ws, const std::string& name = "", bool isView = true)
+bool isDocumentLoaded(std::shared_ptr<LOOLWebSocket>& ws, const std::string& testname = "", bool isView = true)
{
- return isDocumentLoaded(*ws, name, isView);
+ return isDocumentLoaded(*ws, testname, isView);
}
// Connecting to a Kit process is managed by document broker, that it does several
@@ -325,9 +357,9 @@ std::shared_ptr<LOOLWebSocket>
connectLOKit(const Poco::URI& uri,
Poco::Net::HTTPRequest& request,
Poco::Net::HTTPResponse& response,
- const std::string& name = "")
+ const std::string& testname = "")
{
- std::cerr << name << "Connecting... ";
+ TST_LOG_BEGIN("Connecting... ");
int retries = 10;
do
{
@@ -336,40 +368,41 @@ connectLOKit(const Poco::URI& uri,
std::unique_ptr<Poco::Net::HTTPClientSession> session(createSession(uri));
auto ws = std::make_shared<LOOLWebSocket>(*session, request, response);
const char* expected_response = "statusindicator: ready";
- if (getResponseString(ws, expected_response, name) == expected_response)
+ if (getResponseString(ws, expected_response, testname) == expected_response)
{
return ws;
}
- std::cerr << (11 - retries);
+ TST_LOG_APPEND(11 - retries);
}
catch (const std::exception& ex)
{
- std::cerr << std::endl << "Error connecting: " << ex.what() << std::endl;
+ TST_LOG_END;
+ TST_LOG("Error connecting: " << ex.what());
}
std::this_thread::sleep_for(std::chrono::milliseconds(POLL_TIMEOUT_MS));
}
while (retries--);
- std::cerr << std::endl;
+ TST_LOG_END;
throw std::runtime_error("Cannot connect to [" + uri.toString() + "].");
}
inline
-std::shared_ptr<LOOLWebSocket> loadDocAndGetSocket(const Poco::URI& uri, const std::string& documentURL, const std::string& name = "", bool isView = true)
+std::shared_ptr<LOOLWebSocket> loadDocAndGetSocket(const Poco::URI& uri, const std::string& documentURL, const std::string& testname = "", bool isView = true)
{
try
{
// Load a document and get its status.
Poco::Net::HTTPRequest request(Poco::Net::HTTPRequest::HTTP_GET, documentURL);
Poco::Net::HTTPResponse response;
- std::shared_ptr<LOOLWebSocket> socket = connectLOKit(uri, request, response, name);
+ std::shared_ptr<LOOLWebSocket> socket = connectLOKit(uri, request, response, testname);
- sendTextFrame(socket, "load url=" + documentURL, name);
- CPPUNIT_ASSERT_MESSAGE("cannot load the document " + documentURL, isDocumentLoaded(*socket, name, isView));
+ sendTextFrame(socket, "load url=" + documentURL, testname);
+ CPPUNIT_ASSERT_MESSAGE("cannot load the document " + documentURL, isDocumentLoaded(*socket, testname, isView));
- std::cerr << name << "Loaded document [" << documentURL << "]." << std::endl;
+ TST_LOG("Loaded document [" << documentURL << "].");
return socket;
}
catch (const Poco::Exception& exc)
@@ -382,13 +415,13 @@ std::shared_ptr<LOOLWebSocket> loadDocAndGetSocket(const Poco::URI& uri, const s
}
inline
-std::shared_ptr<LOOLWebSocket> loadDocAndGetSocket(const std::string& docFilename, const Poco::URI& uri, const std::string& name = "", bool isView = true)
+std::shared_ptr<LOOLWebSocket> loadDocAndGetSocket(const std::string& docFilename, const Poco::URI& uri, const std::string& testname = "", bool isView = true)
{
try
{
std::string documentPath, documentURL;
- getDocumentPathAndURL(docFilename, documentPath, documentURL, name);
- return loadDocAndGetSocket(uri, documentURL, name, isView);
+ getDocumentPathAndURL(docFilename, documentPath, documentURL, testname);
+ return loadDocAndGetSocket(uri, documentURL, testname, isView);
}
catch (const Poco::Exception& exc)
{
@@ -400,7 +433,7 @@ std::shared_ptr<LOOLWebSocket> loadDocAndGetSocket(const std::string& docFilenam
}
inline
-void SocketProcessor(const std::string& name,
+void SocketProcessor(const std::string& testname,
const std::shared_ptr<LOOLWebSocket>& socket,
const std::function<bool(const std::string& msg)>& handler,
const size_t timeoutMs = 10000)
@@ -415,12 +448,12 @@ void SocketProcessor(const std::string& name,
{
if (!socket->poll(waitTime, Poco::Net::Socket::SELECT_READ))
{
- std::cerr << name << "Timeout polling." << std::endl;
+ TST_LOG("Timeout polling.");
break;
}
n = socket->receiveFrame(buffer, sizeof(buffer), flags);
- std::cerr << name << "Got " << LOOLProtocol::getAbbreviatedFrameDump(buffer, n, flags) << std::endl;
+ TST_LOG("Got " << LOOLProtocol::getAbbreviatedFrameDump(buffer, n, flags));
if (n > 0 && (flags & Poco::Net::WebSocket::FRAME_OP_BITMASK) != Poco::Net::WebSocket::FRAME_OP_CLOSE)
{
if (!handler(std::string(buffer, n)))
@@ -454,15 +487,15 @@ void parseDocSize(const std::string& message, const std::string& type,
}
inline
-std::vector<char> getTileMessage(LOOLWebSocket& ws, const std::string& name = "")
+std::vector<char> getTileMessage(LOOLWebSocket& ws, const std::string& testname = "")
{
- return getResponseMessage(ws, "tile", name);
+ return getResponseMessage(ws, "tile", testname);
}
inline
-std::vector<char> assertTileMessage(LOOLWebSocket& ws, const std::string& name = "")
+std::vector<char> assertTileMessage(LOOLWebSocket& ws, const std::string& testname = "")
{
- const std::vector<char> response = getTileMessage(ws, name);
+ const std::vector<char> response = getTileMessage(ws, testname);
const std::string firstLine = LOOLProtocol::getFirstLine(response);
Poco::StringTokenizer tileTokens(firstLine, " ", Poco::StringTokenizer::TOK_IGNORE_EMPTY | Poco::StringTokenizer::TOK_TRIM);
@@ -479,9 +512,9 @@ std::vector<char> assertTileMessage(LOOLWebSocket& ws, const std::string& name =
}
inline
-std::vector<char> assertTileMessage(const std::shared_ptr<LOOLWebSocket>& ws, const std::string& name = "")
+std::vector<char> assertTileMessage(const std::shared_ptr<LOOLWebSocket>& ws, const std::string& testname = "")
{
- return assertTileMessage(*ws, name);
+ return assertTileMessage(*ws, testname);
}
enum SpecialKey { skNone=0, skShift=0x1000, skCtrl=0x2000, skAlt=0x4000 };
@@ -549,11 +582,11 @@ inline std::vector<char> getTileAndSave(std::shared_ptr<LOOLWebSocket>& socket,
const std::string& filename,
const std::string& testname)
{
- std::cerr << testname << "Requesting: " << req << std::endl;
+ TST_LOG("Requesting: " << req);
sendTextFrame(socket, req, testname);
const std::vector<char> tile = getResponseMessage(socket, "tile:", testname);
- std::cerr << testname << " Tile PNG size: " << tile.size() << std::endl;
+ TST_LOG(" Tile PNG size: " << tile.size());
const std::string firstLine = LOOLProtocol::getFirstLine(tile);
std::vector<char> res(tile.begin() + firstLine.size() + 1, tile.end());
@@ -565,7 +598,7 @@ inline std::vector<char> getTileAndSave(std::shared_ptr<LOOLWebSocket>& socket,
std::fstream outStream(filename, std::ios::out);
outStream.write(res.data(), res.size());
outStream.close();
- std::cerr << testname << "Saved [" << firstLine << "] to [" << filename << "]" << std::endl;
+ TST_LOG("Saved [" << firstLine << "] to [" << filename << "]");
}
return res;
@@ -589,7 +622,7 @@ inline void getServerVersion(LOOLWebSocket& socket,
assert(stream.get() == '.');
stream >> minor;
- std::cerr << testname << "Client [" << major << '.' << minor << "]." << std::endl;
+ TST_LOG("Client [" << major << '.' << minor << "].");
}
inline void getServerVersion(std::shared_ptr<LOOLWebSocket>& socket,
diff --git a/test/httpcrashtest.cpp b/test/httpcrashtest.cpp
index 38c2961d..fa79c8be 100644
--- a/test/httpcrashtest.cpp
+++ b/test/httpcrashtest.cpp
@@ -93,12 +93,16 @@ public:
void setUp()
{
+ resetTestStartTime();
testCountHowManyLoolkits();
+ resetTestStartTime();
}
void tearDown()
{
+ resetTestStartTime();
testNoExtraLoolKitsLeft();
+ resetTestStartTime();
}
};
@@ -111,7 +115,7 @@ void HTTPCrashTest::testBarren()
killLoKitProcesses();
countLoolKitProcesses(0);
- std::cerr << "Loading after kill." << std::endl;
+ TST_LOG("Loading after kill.");
// Load a document and get its status.
std::shared_ptr<LOOLWebSocket> socket = loadDocAndGetSocket("hello.odt", _uri, testname);
@@ -132,14 +136,14 @@ void HTTPCrashTest::testCrashKit()
{
std::shared_ptr<LOOLWebSocket> socket = loadDocAndGetSocket("empty.odt", _uri, testname);
- std::cerr << "Killing loolkit instances." << std::endl;
+ TST_LOG("Killing loolkit instances.");
killLoKitProcesses();
countLoolKitProcesses(0);
// We expect the client connection to close.
// In the future we might restore the kit, but currently we don't.
- std::cerr << "Reading after kill." << std::endl;
+ TST_LOG("Reading after kill.");
// Drain the socket.
getResponseMessage(socket, "", testname, 1000);
@@ -149,16 +153,16 @@ void HTTPCrashTest::testCrashKit()
CPPUNIT_ASSERT_EQUAL(static_cast<int>(Poco::Net::WebSocket::WS_ENDPOINT_GOING_AWAY), statusCode);
// respond close frame
- std::cerr << "Shutting down socket." << std::endl;
+ TST_LOG("Shutting down socket.");
socket->shutdown();
- std::cerr << "Reading after shutdown." << std::endl;
+ TST_LOG("Reading after shutdown.");
// no more messages is received.
int flags;
char buffer[READ_BUFFER_SIZE];
const int bytes = socket->receiveFrame(buffer, sizeof(buffer), flags);
- std::cerr << testname << "Got " << LOOLProtocol::getAbbreviatedFrameDump(buffer, bytes, flags) << std::endl;
+ TST_LOG(testname << "Got " << LOOLProtocol::getAbbreviatedFrameDump(buffer, bytes, flags));
// While we expect no more messages after shutdown call, apparently
// sometimes we _do_ get data. Even when the receiveFrame in the loop
@@ -181,13 +185,13 @@ void HTTPCrashTest::testRecoverAfterKitCrash()
{
std::shared_ptr<LOOLWebSocket> socket = loadDocAndGetSocket("empty.odt", _uri, testname);
- std::cerr << "Killing loolkit instances." << std::endl;
+ TST_LOG("Killing loolkit instances.");
killLoKitProcesses();
countLoolKitProcesses(0);
// We expect the client connection to close.
- std::cerr << "Reconnect after kill." << std::endl;
+ TST_LOG("Reconnect after kill.");
std::shared_ptr<LOOLWebSocket> socket2 = loadDocAndGetSocket("empty.odt", _uri, testname);
sendTextFrame(socket2, "status", testname);
@@ -206,9 +210,9 @@ void HTTPCrashTest::testCrashForkit()
{
std::shared_ptr<LOOLWebSocket> socket = loadDocAndGetSocket("empty.odt", _uri, testname);
- std::cerr << "Killing forkit." << std::endl;
+ TST_LOG("Killing forkit.");
killForkitProcess();
- std::cerr << "Communicating after kill." << std::endl;
+ TST_LOG("Communicating after kill.");
sendTextFrame(socket, "status", testname);
assertResponseString(socket, "status:", testname);
@@ -216,10 +220,10 @@ void HTTPCrashTest::testCrashForkit()
// respond close frame
socket->shutdown();
- std::cerr << "Killing loolkit." << std::endl;
+ TST_LOG("Killing loolkit.");
killLoKitProcesses();
countLoolKitProcesses(0);
- std::cerr << "Communicating after kill." << std::endl;
+ TST_LOG("Communicating after kill.");
loadDocAndGetSocket("empty.odt", _uri, testname);
}
catch (const Poco::Exception& exc)
@@ -228,26 +232,27 @@ void HTTPCrashTest::testCrashForkit()
}
}
-void killPids(const std::vector<int> &pids)
+static void killPids(const std::vector<int> &pids, const std::string& testname)
{
- std::cout << "kill pids " << pids.size() << "\n";
+ TST_LOG("kill pids " << pids.size());
// Now kill them
for (int pid : pids)
{
- std::cerr << "Killing " << pid << std::endl;
+ TST_LOG_BEGIN("Killing " << pid);
if (kill(pid, SIGKILL) == -1)
- std::cerr << "kill(" << pid << ", SIGKILL) failed: " << std::strerror(errno) << std::endl;
+ TST_LOG_APPEND("kill(" << pid << ", SIGKILL) failed: " << std::strerror(errno));
+ TST_LOG_END;
}
}
void HTTPCrashTest::killLoKitProcesses()
{
- killPids(getKitPids());
+ killPids(getKitPids(), "killLoKitProcesses ");
}
void HTTPCrashTest::killForkitProcess()
{
- killPids(getForKitPids());
+ killPids(getForKitPids(), "killForkitProcess ");
}
CPPUNIT_TEST_SUITE_REGISTRATION(HTTPCrashTest);
diff --git a/test/httpwserror.cpp b/test/httpwserror.cpp
index 6ba40d01..16c27d8f 100644
--- a/test/httpwserror.cpp
+++ b/test/httpwserror.cpp
@@ -74,12 +74,16 @@ public:
void setUp()
{
+ resetTestStartTime();
testCountHowManyLoolkits();
+ resetTestStartTime();
}
void tearDown()
{
+ resetTestStartTime();
testNoExtraLoolKitsLeft();
+ resetTestStartTime();
}
};
diff --git a/test/httpwstest.cpp b/test/httpwstest.cpp
index ad0980bb..99bcff0e 100644
--- a/test/httpwstest.cpp
+++ b/test/httpwstest.cpp
@@ -179,7 +179,8 @@ class HTTPWSTest : public CPPUNIT_NS::TestFixture
const size_t thread_count,
const size_t max_jitter_ms);
- void getPartHashCodes(const std::string response,
+ void getPartHashCodes(const std::string& testname,
+ const std::string& response,
std::vector<std::string>& parts);
void getCursor(const std::string& message,
@@ -225,12 +226,16 @@ public:
void setUp()
{
+ resetTestStartTime();
testCountHowManyLoolkits();
+ resetTestStartTime();
}
void tearDown()
{
+ resetTestStartTime();
testNoExtraLoolKitsLeft();
+ resetTestStartTime();
}
};
@@ -279,17 +284,17 @@ void HTTPWSTest::testHandshake()
int flags = 0;
char buffer[1024] = {0};
int bytes = socket.receiveFrame(buffer, sizeof(buffer), flags);
- std::cerr << testname << "Got " << LOOLProtocol::getAbbreviatedFrameDump(buffer, bytes, flags) << std::endl;
+ TST_LOG("Got " << LOOLProtocol::getAbbreviatedFrameDump(buffer, bytes, flags));
CPPUNIT_ASSERT_EQUAL(std::string("statusindicator: find"), std::string(buffer, bytes));
bytes = socket.receiveFrame(buffer, sizeof(buffer), flags);
- std::cerr << testname << "Got " << LOOLProtocol::getAbbreviatedFrameDump(buffer, bytes, flags) << std::endl;
+ TST_LOG("Got " << LOOLProtocol::getAbbreviatedFrameDump(buffer, bytes, flags));
if (bytes > 0 && !std::strstr(buffer, "error:"))
{
CPPUNIT_ASSERT_EQUAL(std::string("statusindicator: connect"), std::string(buffer, bytes));
bytes = socket.receiveFrame(buffer, sizeof(buffer), flags);
- std::cerr << testname << "Got " << LOOLProtocol::getAbbreviatedFrameDump(buffer, bytes, flags) << std::endl;
+ TST_LOG("Got " << LOOLProtocol::getAbbreviatedFrameDump(buffer, bytes, flags));
if (!std::strstr(buffer, "error:"))
{
CPPUNIT_ASSERT_EQUAL(std::string("statusindicator: ready"), std::string(buffer, bytes));
@@ -301,7 +306,7 @@ void HTTPWSTest::testHandshake()
// close frame message
bytes = socket.receiveFrame(buffer, sizeof(buffer), flags);
- std::cerr << testname << "Got " << LOOLProtocol::getAbbreviatedFrameDump(buffer, bytes, flags) << std::endl;
+ TST_LOG("Got " << LOOLProtocol::getAbbreviatedFrameDump(buffer, bytes, flags));
CPPUNIT_ASSERT((flags & Poco::Net::WebSocket::FRAME_OP_BITMASK) == Poco::Net::WebSocket::FRAME_OP_CLOSE);
}
}
@@ -312,7 +317,7 @@ void HTTPWSTest::testHandshake()
// close frame message
bytes = socket.receiveFrame(buffer, sizeof(buffer), flags);
- std::cerr << testname << "Got " << LOOLProtocol::getAbbreviatedFrameDump(buffer, bytes, flags) << std::endl;
+ TST_LOG("Got " << LOOLProtocol::getAbbreviatedFrameDump(buffer, bytes, flags));
CPPUNIT_ASSERT((flags & Poco::Net::WebSocket::FRAME_OP_BITMASK) == Poco::Net::WebSocket::FRAME_OP_CLOSE);
}
}
@@ -327,11 +332,11 @@ void HTTPWSTest::testCloseAfterClose()
const char* testname = "closeAfterClose ";
try
{
- std::cerr << testname << "Connecting and loading." << std::endl;
+ TST_LOG("Connecting and loading.");
std::shared_ptr<LOOLWebSocket> socket = loadDocAndGetSocket("hello.odt", _uri, testname);
// send normal socket shutdown
- std::cerr << testname << "Disconnecting." << std::endl;
+ TST_LOG("Disconnecting.");
socket->shutdown();
// 5 seconds timeout
@@ -344,17 +349,17 @@ void HTTPWSTest::testCloseAfterClose()
do
{
bytes = socket->receiveFrame(buffer, sizeof(buffer), flags);
- std::cerr << testname << "Received [" << std::string(buffer, bytes) << "], flags: "<< std::hex << flags << std::dec << std::endl;
+ TST_LOG("Received [" << std::string(buffer, bytes) << "], flags: "<< std::hex << flags << std::dec);
}
while (bytes > 0 && (flags & Poco::Net::WebSocket::FRAME_OP_BITMASK) != Poco::Net::WebSocket::FRAME_OP_CLOSE);
- std::cerr << testname << "Received " << bytes << " bytes, flags: "<< std::hex << flags << std::dec << std::endl;
+ TST_LOG("Received " << bytes << " bytes, flags: "<< std::hex << flags << std::dec);
try
{
// no more messages is received.
bytes = socket->receiveFrame(buffer, sizeof(buffer), flags);
- std::cerr << testname << "Received " << bytes << " bytes, flags: "<< std::hex << flags << std::dec << std::endl;
+ TST_LOG("Received " << bytes << " bytes, flags: "<< std::hex << flags << std::dec);
CPPUNIT_ASSERT_EQUAL(0, bytes);
CPPUNIT_ASSERT_EQUAL(0, flags);
}
@@ -363,7 +368,7 @@ void HTTPWSTest::testCloseAfterClose()
// This is not unexpected, since WSD will close the socket after
// echoing back the shutdown status code. However, if it doesn't
// we assert above that it doesn't send any more data.
- std::cerr << testname << "Error: " << exc.displayText() << std::endl;
+ TST_LOG("Error: " << exc.displayText());
}
}
@@ -402,31 +407,31 @@ void HTTPWSTest::testConnectNoLoad()
// Connect and disconnect without loading.
Poco::Net::HTTPRequest request(Poco::Net::HTTPRequest::HTTP_GET, documentURL);
- std::cerr << testname1 << "Connecting first to disconnect without loading." << std::endl;
+ TST_LOG_NAME(testname1, "Connecting first to disconnect without loading.");
std::shared_ptr<LOOLWebSocket> socket = connectLOKit(_uri, request, _response, testname1);
CPPUNIT_ASSERT_MESSAGE("Failed to connect.", socket);
- std::cerr << testname1 << "Disconnecting first." << std::endl;
+ TST_LOG_NAME(testname1, "Disconnecting first.");
socket.reset();
// Connect and load first view.
- std::cerr << testname2 << "Connecting second to load first view." << std::endl;
+ TST_LOG_NAME(testname2, "Connecting second to load first view.");
std::shared_ptr<LOOLWebSocket> socket1 = connectLOKit(_uri, request, _response, testname2);
CPPUNIT_ASSERT_MESSAGE("Failed to connect.", socket1);
sendTextFrame(socket1, "load url=" + documentURL, testname2);
CPPUNIT_ASSERT_MESSAGE("cannot load the document " + documentURL, isDocumentLoaded(socket1));
// Connect but don't load second view.
- std::cerr << testname3 << "Connecting third to disconnect without loading." << std::endl;
+ TST_LOG_NAME(testname3, "Connecting third to disconnect without loading.");
std::shared_ptr<LOOLWebSocket> socket2 = connectLOKit(_uri, request, _response, testname3);
CPPUNIT_ASSERT_MESSAGE("Failed to connect.", socket2);
- std::cerr << testname3 << "Disconnecting third." << std::endl;
+ TST_LOG_NAME(testname3, "Disconnecting third.");
socket2.reset();
- std::cerr << testname2 << "Getting status from first view." << std::endl;
+ TST_LOG_NAME(testname2, "Getting status from first view.");
sendTextFrame(socket1, "status", testname2);
assertResponseString(socket1, "status:");
- std::cerr << testname2 << "Disconnecting second." << std::endl;
+ TST_LOG_NAME(testname2, "Disconnecting second.");
socket1.reset();
}
@@ -462,7 +467,7 @@ int HTTPWSTest::loadTorture(const std::string& testname,
oss << std::hex << std::this_thread::get_id();
const std::string id = oss.str();
- std::cerr << testname << ": #" << id << ", views: " << num_of_views << ", to load: " << num_to_load << std::endl;
+ TST_LOG(": #" << id << ", views: " << num_of_views << ", to load: " << num_to_load);
try
{
// Load a document and wait for the status.
@@ -478,14 +483,14 @@ int HTTPWSTest::loadTorture(const std::string& testname,
++num_of_views;
--num_to_load;
- std::cerr << testname << ": #" << id << ", loaded views: " << num_of_views << ", to load: " << num_to_load << std::endl;
+ TST_LOG(": #" << id << ", loaded views: " << num_of_views << ", to load: " << num_to_load);
while (true)
{
if (num_to_load == 0)
{
// Unload at once, nothing more left to do.
- std::cerr << testname << ": #" << id << ", no more to load, unloading." << std::endl;
+ TST_LOG(": #" << id << ", no more to load, unloading.");
break;
}
@@ -497,7 +502,7 @@ int HTTPWSTest::loadTorture(const std::string& testname,
// Unload only when we aren't the last/only.
if (--num_of_views > 0)
{
- std::cerr << testname << ": #" << id << ", views: " << num_of_views << " not the last/only, unloading." << std::endl;
+ TST_LOG(": #" << id << ", views: " << num_of_views << " not the last/only, unloading.");
break;
}
else
@@ -509,7 +514,7 @@ int HTTPWSTest::loadTorture(const std::string& testname,
}
catch (const std::exception& exc)
{
- std::cerr << testname << ": #" << id << ", Exception: " << exc.what() << std::endl;
+ TST_LOG(": #" << id << ", Exception: " << exc.what());
--num_to_load;
}
});
@@ -523,7 +528,7 @@ int HTTPWSTest::loadTorture(const std::string& testname,
}
catch (const std::exception& exc)
{
- std::cerr << testname << ": Exception: " << exc.what() << std::endl;
+ TST_LOG(": Exception: " << exc.what());
}
}
@@ -627,7 +632,7 @@ void HTTPWSTest::testReload()
getDocumentPathAndURL("hello.odt", documentPath, documentURL, testname);
for (int i = 0; i < 3; ++i)
{
- std::cerr << testname << "loading #" << (i+1) << std::endl;
+ TST_LOG("loading #" << (i+1));
loadDoc(documentURL, testname);
}
}
@@ -659,7 +664,7 @@ void HTTPWSTest::testSaveOnDisconnect()
const char* testname = "saveOnDisconnect ";
const std::string text = helpers::genRandomString(40);
- std::cerr << "Test string: [" << text << "]." << std::endl;
+ TST_LOG("Test string: [" << text << "].");
std::string documentPath, documentURL;
getDocumentPathAndURL("hello.odt", documentPath, documentURL, testname);
@@ -676,6 +681,8 @@ void HTTPWSTest::testSaveOnDisconnect()
sendTextFrame(socket, "uno .uno:Delete", testname);
sendTextFrame(socket, "paste mimetype=text/plain;charset=utf-8\n" + text, testname);
+ TST_LOG("Validating what we sent before disconnecting.");
+
// Check if the document contains the pasted text.
sendTextFrame(socket, "uno .uno:SelectAll", testname);
sendTextFrame(socket, "gettextselection mimetype=text/plain;charset=utf-8", testname);
@@ -690,7 +697,7 @@ void HTTPWSTest::testSaveOnDisconnect()
kitcount = getLoolKitProcessCount();
// Shutdown abruptly.
- std::cerr << "Closing connection after pasting." << std::endl;
+ TST_LOG("Closing connection after pasting.");
socket->shutdown();
socket2->shutdown();
}
@@ -701,7 +708,7 @@ void HTTPWSTest::testSaveOnDisconnect()
// Allow time to save and destroy before we connect again.
testNoExtraLoolKitsLeft();
- std::cerr << "Loading again." << std::endl;
+ TST_LOG("Loading again.");
try
{
// Load the same document and check that the last changes (pasted text) is saved.
@@ -727,7 +734,7 @@ void HTTPWSTest::testSavePassiveOnDisconnect()
const char* testname = "saveOnPassiveDisconnect ";
const std::string text = helpers::genRandomString(40);
- std::cerr << "Test string: [" << text << "]." << std::endl;
+ TST_LOG("Test string: [" << text << "].");
std::string documentPath, documentURL;
getDocumentPathAndURL("hello.odt", documentPath, documentURL, testname);
@@ -758,7 +765,7 @@ void HTTPWSTest::testSavePassiveOnDisconnect()
kitcount = getLoolKitProcessCount();
// Shutdown abruptly.
- std::cerr << "Closing connection after pasting." << std::endl;
+ TST_LOG("Closing connection after pasting.");
socket->shutdown(); // Should trigger saving.
socket2->shutdown();
}
@@ -769,7 +776,7 @@ void HTTPWSTest::testSavePassiveOnDisconnect()
// Allow time to save and destroy before we connect again.
testNoExtraLoolKitsLeft();
- std::cerr << "Loading again." << std::endl;
+ TST_LOG("Loading again.");
try
{
// Load the same document and check that the last changes (pasted text) is saved.
@@ -812,11 +819,11 @@ void HTTPWSTest::testReloadWhileDisconnecting()
const int kitcount = getLoolKitProcessCount();
// Shutdown abruptly.
- std::cerr << "Closing connection after pasting." << std::endl;
+ TST_LOG("Closing connection after pasting.");
socket->shutdown();
// Load the same document and check that the last changes (pasted text) is saved.
- std::cerr << "Loading again." << std::endl;
+ TST_LOG("Loading again.");
socket = loadDocAndGetSocket(_uri, documentURL, testname);
// Should have no new instances.
@@ -858,26 +865,28 @@ void HTTPWSTest::testExcelLoad()
void HTTPWSTest::testPaste()
{
const char* testname = "paste ";
- try
+
+ // Load a document and make it empty, then paste some text into it.
+ std::shared_ptr<LOOLWebSocket> socket = loadDocAndGetSocket("hello.odt", _uri, testname);
+
+ for (int i = 0; i < 5; ++i)
{
- // Load a document and make it empty, then paste some text into it.
- std::shared_ptr<LOOLWebSocket> socket = loadDocAndGetSocket("hello.odt", _uri, testname);
+ const std::string text = std::to_string(i + 1) + "_sh9le[;\"CFD7U[#B+_nW=$kXgx{sv9QE#\"l1y\"hr_" + Util::encodeId(Util::rng::getNext());
+ TST_LOG("Pasting text #" << i + 1 << ": " << text);
+ // Always delete everything to have an empty doc.
sendTextFrame(socket, "uno .uno:SelectAll", testname);
sendTextFrame(socket, "uno .uno:Delete", testname);
// Paste some text into it.
- sendTextFrame(socket, "paste mimetype=text/plain;charset=utf-8\naaa bbb ccc", testname);
+ sendTextFrame(socket, "paste mimetype=text/plain;charset=utf-8\n" + text, testname);
+ const std::string expected = "textselectioncontent: " + text;
// Check if the document contains the pasted text.
sendTextFrame(socket, "uno .uno:SelectAll", testname);
sendTextFrame(socket, "gettextselection mimetype=text/plain;charset=utf-8", testname);
const auto selection = assertResponseString(socket, "textselectioncontent:", testname);
- CPPUNIT_ASSERT_EQUAL(std::string("textselectioncontent: aaa bbb ccc"), selection);
- }
- catch (const Poco::Exception& exc)
- {
- CPPUNIT_FAIL(exc.displayText());
+ CPPUNIT_ASSERT_EQUAL(expected, selection);
}
}
@@ -926,7 +935,7 @@ void HTTPWSTest::testLargePaste()
}
const std::string documentContents = oss.str();
- std::cerr << "Pasting " << documentContents.size() << " characters into document." << std::endl;
+ TST_LOG("Pasting " << documentContents.size() << " characters into document.");
sendTextFrame(socket, "paste mimetype=text/html\n" + documentContents, testname);
// Check if the server is still alive.
@@ -1130,23 +1139,23 @@ void HTTPWSTest::testInsertDelete()
CPPUNIT_ASSERT_MESSAGE("cannot load the document " + documentURL, isDocumentLoaded(socket));
// check total slides 1
- std::cerr << "Expecting 1 slide." << std::endl;
+ TST_LOG("Expecting 1 slide.");
sendTextFrame(socket, "status");
response = getResponseString(socket, "status:");
CPPUNIT_ASSERT_MESSAGE("did not receive a status: message as expected", !response.empty());
- getPartHashCodes(response.substr(7), parts);
+ getPartHashCodes(testname, response.substr(7), parts);
CPPUNIT_ASSERT_EQUAL(1, (int)parts.size());
const std::string slide1Hash = parts[0];
// insert 10 slides
- std::cerr << "Inserting 10 slides." << std::endl;
+ TST_LOG("Inserting 10 slides.");
for (size_t it = 1; it <= 10; it++)
{
sendTextFrame(socket, "uno .uno:InsertPage");
response = getResponseString(socket, "status:");
CPPUNIT_ASSERT_MESSAGE("did not receive a status: message as expected", !response.empty());
- getPartHashCodes(response.substr(7), parts);
+ getPartHashCodes(testname, response.substr(7), parts);
CPPUNIT_ASSERT_EQUAL(it + 1, parts.size());
}
@@ -1154,7 +1163,7 @@ void HTTPWSTest::testInsertDelete()
const std::vector<std::string> parts_after_insert(parts.begin(), parts.end());
// delete 10 slides
- std::cerr << "Deleting 10 slides." << std::endl;
+ TST_LOG("Deleting 10 slides.");
for (size_t it = 1; it <= 10; it++)
{
// Explicitly delete the nth slide.
@@ -1162,20 +1171,20 @@ void HTTPWSTest::testInsertDelete()
sendTextFrame(socket, "uno .uno:DeletePage");
response = getResponseString(socket, "status:");
CPPUNIT_ASSERT_MESSAGE("did not receive a status: message as expected", !response.empty());
- getPartHashCodes(response.substr(7), parts);
+ getPartHashCodes(testname, response.substr(7), parts);
CPPUNIT_ASSERT_EQUAL(11 - it, parts.size());
}
CPPUNIT_ASSERT_MESSAGE("Hash code of slide #1 changed after deleting extra slides.", parts[0] == slide1Hash);
// undo delete slides
- std::cerr << "Undoing 10 slide deletes." << std::endl;
+ TST_LOG("Undoing 10 slide deletes.");
for (size_t it = 1; it <= 10; it++)
{
sendTextFrame(socket, "uno .uno:Undo");
response = getResponseString(socket, "status:");
CPPUNIT_ASSERT_MESSAGE("did not receive a status: message as expected", !response.empty());
- getPartHashCodes(response.substr(7), parts);
+ getPartHashCodes(testname, response.substr(7), parts);
CPPUNIT_ASSERT_EQUAL(it + 1, parts.size());
}
@@ -1184,24 +1193,24 @@ void HTTPWSTest::testInsertDelete()
CPPUNIT_ASSERT_MESSAGE("Hash codes changed between deleting and undo.", parts_after_insert == parts_after_undo);
// redo inserted slides
- std::cerr << "Redoing 10 slide deletes." << std::endl;
+ TST_LOG("Redoing 10 slide deletes.");
for (size_t it = 1; it <= 10; it++)
{
sendTextFrame(socket, "uno .uno:Redo");
response = getResponseString(socket, "status:");
CPPUNIT_ASSERT_MESSAGE("did not receive a status: message as expected", !response.empty());
- getPartHashCodes(response.substr(7), parts);
+ getPartHashCodes(testname, response.substr(7), parts);
CPPUNIT_ASSERT_EQUAL(11 - it, parts.size());
}
CPPUNIT_ASSERT_MESSAGE("Hash code of slide #1 changed after redoing slide delete.", parts[0] == slide1Hash);
// check total slides 1
- std::cerr << "Expecting 1 slide." << std::endl;
+ TST_LOG("Expecting 1 slide.");
sendTextFrame(socket, "status");
response = getResponseString(socket, "status:");
CPPUNIT_ASSERT_MESSAGE("did not receive a status: message as expected", !response.empty());
- getPartHashCodes(response.substr(7), parts);
+ getPartHashCodes(testname, response.substr(7), parts);
CPPUNIT_ASSERT_EQUAL(1, (int)parts.size());
}
catch (const Poco::Exception& exc)
@@ -1276,7 +1285,7 @@ void HTTPWSTest::testSlideShow()
std::istream& rs = session->receiveResponse(responseSVG);
CPPUNIT_ASSERT_EQUAL(Poco::Net::HTTPResponse::HTTP_OK, responseSVG.getStatus());
CPPUNIT_ASSERT_EQUAL(std::string("image/svg+xml"), responseSVG.getContentType());
- std::cerr << "SVG file size: " << responseSVG.getContentLength() << std::endl;
+ TST_LOG("SVG file size: " << responseSVG.getContentLength());
// std::ofstream ofs("/tmp/slide.svg");
// Poco::StreamCopier::copyStream(rs, ofs);
@@ -1315,7 +1324,7 @@ void HTTPWSTest::testInactiveClient()
std::shared_ptr<LOOLWebSocket> socket1 = loadDocAndGetSocket(_uri, documentURL, "inactiveClient-1 ");
// Connect another and go inactive.
- std::cerr << "Connecting second client." << std::endl;
+ TST_LOG("Connecting second client.");
std::shared_ptr<LOOLWebSocket> socket2 = loadDocAndGetSocket(_uri, documentURL, "inactiveClient-2 ", true);
sendTextFrame(socket2, "userinactive", "inactiveClient-2 ");
@@ -1349,7 +1358,7 @@ void HTTPWSTest::testInactiveClient()
return (token != "statechanged:");
});
- std::cerr << "Second client finished." << std::endl;
+ TST_LOG("Second client finished.");
socket1->shutdown();
socket2->shutdown();
}
@@ -1437,14 +1446,15 @@ void HTTPWSTest::testMaxRow()
}
}
-void HTTPWSTest::getPartHashCodes(const std::string status,
+void HTTPWSTest::getPartHashCodes(const std::string& testname,
+ const std::string& response,
std::vector<std::string>& parts)
{
std::string line;
- std::istringstream istr(status);
+ std::istringstream istr(response);
std::getline(istr, line);
- std::cerr << "Reading parts from [" << status << "]." << std::endl;
+ TST_LOG("Reading parts from [" << response << "].");
// Expected format is something like 'type= parts= current= width= height= viewid='.
Poco::StringTokenizer tokens(line, " ", Poco::StringTokenizer::TOK_IGNORE_EMPTY | Poco::StringTokenizer::TOK_TRIM);
@@ -1455,7 +1465,7 @@ void HTTPWSTest::getPartHashCodes(const std::string status,
type == "presentation" || type == "spreadsheet");
const int totalParts = std::stoi(tokens[1].substr(std::string("parts=").size()));
- std::cerr << "Status reports " << totalParts << " parts." << std::endl;
+ TST_LOG("Status reports " << totalParts << " parts.");
Poco::RegularExpression endLine("[^\n\r]+");
Poco::RegularExpression number("^[0-9]+$");
@@ -1463,10 +1473,10 @@ void HTTPWSTest::getPartHashCodes(const std::string status,
int offset = 0;
parts.clear();
- while (endLine.match(status, offset, matches) > 0)
+ while (endLine.match(response, offset, matches) > 0)
{
CPPUNIT_ASSERT_EQUAL(1, (int)matches.size());
- const std::string str = status.substr(matches[0].offset, matches[0].length);
+ const std::string str = response.substr(matches[0].offset, matches[0].length);
if (number.match(str, 0))
{
parts.push_back(str);
@@ -1475,7 +1485,7 @@ void HTTPWSTest::getPartHashCodes(const std::string status,
offset = static_cast<int>(matches[0].offset + matches[0].length);
}
- std::cerr << "Found " << parts.size() << " part names/codes." << std::endl;
+ TST_LOG("Found " << parts.size() << " part names/codes.");
// Validate that Core is internally consistent when emitting status messages.
CPPUNIT_ASSERT_EQUAL(totalParts, (int)parts.size());
@@ -1617,7 +1627,7 @@ void HTTPWSTest::testInsertAnnotationWriter()
// Make sure the document is fully unloaded.
testNoExtraLoolKitsLeft();
- std::cerr << "Reloading " << std::endl;
+ TST_LOG("Reloading ");
socket = loadDocAndGetSocket(_uri, documentURL, testname);
// Confirm that the text is in the comment and not doc body.
@@ -1682,10 +1692,10 @@ void HTTPWSTest::testEditAnnotationWriter()
const int kitcount = getLoolKitProcessCount();
// Close and reopen the same document and test again.
- std::cerr << "Closing connection after pasting." << std::endl;
+ TST_LOG("Closing connection after pasting.");
socket->shutdown();
- std::cerr << "Reloading " << std::endl;
+ TST_LOG("Reloading ");
socket = loadDocAndGetSocket(_uri, documentURL, testname);
// Should have no new instances.
@@ -1751,7 +1761,7 @@ void HTTPWSTest::testCalcEditRendering()
sendTextFrame(socket, req, testname);
const std::vector<char> tile = getResponseMessage(socket, "tile:", testname);
- std::cerr << "size: " << tile.size() << std::endl;
+ TST_LOG("size: " << tile.size());
// Return early for now when on LO >= 5.2.
int major = 0;
@@ -1793,7 +1803,7 @@ void HTTPWSTest::testCalcEditRendering()
// This is a very strict test that breaks often/easily due to slight rendering
// differences. So for now just keep it informative only.
//CPPUNIT_ASSERT_MESSAGE("Tile not rendered as expected @ row #" + std::to_string(itRow), eq);
- std::cerr << "\nFAILURE: Tile not rendered as expected @ row #" << itRow << std::endl;
+ TST_LOG("\nFAILURE: Tile not rendered as expected @ row #" << itRow);
break;
}
}
@@ -1817,8 +1827,8 @@ void HTTPWSTest::testCalcRenderAfterNewView51()
getServerVersion(socket, major, minor, testname);
if (major != 5 || minor != 1)
{
- std::cerr << testname << "Skipping test on incompatible client ["
- << major << '.' << minor << "], expected [5.1]." << std::endl;
+ TST_LOG("Skipping test on incompatible client ["
+ << major << '.' << minor << "], expected [5.1].");
return;
}
@@ -1838,12 +1848,12 @@ void HTTPWSTest::testCalcRenderAfterNewView51()
// Connect second client, which will load at the top.
- std::cerr << testname << "Connecting second client." << std::endl;
+ TST_LOG("Connecting second client.");
std::shared_ptr<LOOLWebSocket> socket2 = loadDocAndGetSocket(_uri, documentURL, testname);
// Up one row on the first view to trigger the bug.
- std::cerr << testname << "Up." << std::endl;
+ TST_LOG("Up.");
sendTextFrame(socket, "key type=input char=0 key=1025", testname);
assertResponseString(socket, "invalidatetiles:", testname); // Up invalidates.
@@ -1868,8 +1878,8 @@ void HTTPWSTest::testCalcRenderAfterNewView53()
getServerVersion(socket, major, minor, testname);
if (major < 5 || minor < 3)
{
- std::cerr << testname << "Skipping test on incompatible client ["
- << major << '.' << minor << "], expected [>=5.3]." << std::endl;
+ TST_LOG("Skipping test on incompatible client ["
+ << major << '.' << minor << "], expected [>=5.3].");
return;
}
@@ -1882,11 +1892,11 @@ void HTTPWSTest::testCalcRenderAfterNewView53()
// Connect second client, which will load at the top.
- std::cerr << testname << "Connecting second client." << std::endl;
+ TST_LOG("Connecting second client.");
std::shared_ptr<LOOLWebSocket> socket2 = loadDocAndGetSocket(_uri, documentURL, testname);
- std::cerr << testname << "Waiting for cellviewcursor of second on first." << std::endl;
+ TST_LOG("Waiting for cellviewcursor of second on first.");
assertResponseString(socket, "cellviewcursor:", testname);
// Get same tile again.
diff --git a/test/integration-http-server.cpp b/test/integration-http-server.cpp
index ef478fcb..25fee24d 100644
--- a/test/integration-http-server.cpp
+++ b/test/integration-http-server.cpp
@@ -78,12 +78,16 @@ public:
void setUp()
{
+ helpers::resetTestStartTime();
testCountHowManyLoolkits();
+ helpers::resetTestStartTime();
}
void tearDown()
{
+ helpers::resetTestStartTime();
testNoExtraLoolKitsLeft();
+ helpers::resetTestStartTime();
}
};
diff --git a/wsd/AdminModel.cpp b/wsd/AdminModel.cpp
index 6a9065fd..7f2b8dac 100644
--- a/wsd/AdminModel.cpp
+++ b/wsd/AdminModel.cpp
@@ -169,9 +169,9 @@ void AdminModel::assertCorrectThread() const
// FIXME: share this code [!]
const bool sameThread = std::this_thread::get_id() == _owner;
if (!sameThread)
- LOG_ERR("Admin command invoked from foreign thread. Expected: 0x" << std::hex <<
- _owner << " but called from 0x" << std::this_thread::get_id() << " (" <<
- std::dec << Util::getThreadId() << ").");
+ LOG_ERR("Admin command invoked from foreign thread. Expected: " <<
+ Log::to_string(_owner) << " but called from " <<
+ std::this_thread::get_id() << " (" << Util::getThreadId() << ").");
assert(sameThread);
}
diff --git a/wsd/TileCache.cpp b/wsd/TileCache.cpp
index 95ed5089..51f1933d 100644
--- a/wsd/TileCache.cpp
+++ b/wsd/TileCache.cpp
@@ -537,9 +537,9 @@ void TileCache::assertCorrectThread()
{
const bool correctThread = _owner == std::thread::id(0) || std::this_thread::get_id() == _owner;
if (!correctThread)
- LOG_ERR("TileCache method invoked from foreign thread. Expected: 0x" << std::hex <<
- _owner << " but called from 0x" << std::this_thread::get_id() << " (" <<
- std::dec << Util::getThreadId() << ").");
+ LOG_ERR("TileCache method invoked from foreign thread. Expected: " <<
+ Log::to_string(_owner) << " but called from " <<
+ std::this_thread::get_id() << " (" << Util::getThreadId() << ").");
assert (correctThread);
}
More information about the Libreoffice-commits
mailing list