rayelliott
/
barrier
mirror of https://github.com/debauchee/barrier.git
1
0
Fork 0
Code Issues Projects Releases Wiki Activity

Disabled threading on most IPC logging tests #4624 

Threading was making it very hard to reliably run the IPC logging tests
(many timing issues), so I disabled threading for most of the tests.
This commit is contained in:
Nick Bolton 2015-05-20 17:42:07 +01:00
parent 89a977da66
commit 561204b2a7
6 changed files with 111 additions and 115 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

79
src/lib/ipc/IpcLogOutputter.cpp
View File

@ -37,11 +37,12 @@ enum EIpcLogOutputter {
kBufferRateTimeLimit = 1 // seconds
};
IpcLogOutputter::IpcLogOutputter(IpcServer& ipcServer) :
IpcLogOutputter::IpcLogOutputter(IpcServer& ipcServer, bool useThread) :
m_ipcServer(ipcServer),
m_bufferMutex(ARCH->newMutex()),
m_sending(false),
m_running(true),
m_running(false),
m_bufferThread(nullptr),
m_notifyCond(ARCH->newCondVar()),
m_notifyMutex(ARCH->newMutex()),
m_bufferWaiting(false),
@ -51,8 +52,10 @@ IpcLogOutputter::IpcLogOutputter(IpcServer& ipcServer) :
m_bufferWriteCount(0),
m_bufferRateStart(ARCH->time())
{
m_bufferThread = new Thread(new TMethodJob<IpcLogOutputter>(
this, &IpcLogOutputter::bufferThread));
if (useThread) {
m_bufferThread = new Thread(new TMethodJob<IpcLogOutputter>(
this, &IpcLogOutputter::bufferThread));
}
}
IpcLogOutputter::~IpcLogOutputter()
@ -60,7 +63,10 @@ IpcLogOutputter::~IpcLogOutputter()
close();
ARCH->closeMutex(m_bufferMutex);
delete m_bufferThread;
if (m_bufferThread != nullptr) {
delete m_bufferThread;
}
ARCH->closeCondVar(m_notifyCond);
ARCH->closeMutex(m_notifyMutex);
@ -74,9 +80,11 @@ IpcLogOutputter::open(const char* title)
void
IpcLogOutputter::close()
{
m_running = false;
notifyBuffer();
m_bufferThread->wait(5);
if (m_bufferThread != nullptr) {
m_running = false;
notifyBuffer();
m_bufferThread->wait(5);
}
}
void
@ -85,27 +93,12 @@ IpcLogOutputter::show(bool showIfEmpty)
}
bool
IpcLogOutputter::write(ELevel level, const char* text)
IpcLogOutputter::write(ELevel, const char* text)
{
return write(level, text, false);
}
bool
IpcLogOutputter::write(ELevel, const char* text, bool force)
{
// TODO: discard based on thread id? hmm...
// sending the buffer generates log messages, which we must throw
// away (otherwise this would cause recursion). this is just a drawback
// of logging this way. there is also the risk that this could throw
// away log messages not generated by the ipc, but it seems like it
// would be difficult to distinguish (other than looking at the stack
// trace somehow). perhaps a file stream might be a better option :-/
if (m_sending && !force) {
// ignore events from the buffer thread (would cause recursion).
if (Thread::getCurrentThread().getID() == m_bufferThreadId) {
return true;
}
// ignore events from the buffer thread (would cause recursion).
if (m_bufferThread != nullptr &&
Thread::getCurrentThread().getID() == m_bufferThreadId) {
return true;
}
appendBuffer(text);
@ -143,29 +136,17 @@ IpcLogOutputter::appendBuffer(const String& text)
void
IpcLogOutputter::bufferThread(void*)
{
ArchMutexLock lock(m_notifyMutex);
m_bufferThreadId = m_bufferThread->getID();
m_running = true;
try {
while (m_running) {
if (m_ipcServer.hasClients(kIpcClientGui)) {
// buffer is sent in chunks, so keep sending until it's
// empty (or the program has stopped in the meantime).
while (m_running && !m_buffer.empty()) {
sendBuffer();
}
if (m_buffer.empty()) {
ArchMutexLock lock(m_notifyMutex);
ARCH->waitCondVar(m_notifyCond, m_notifyMutex, -1);
}
// program may be stopping while we were in the send loop.
if (!m_running) {
break;
}
m_bufferWaiting = true;
ARCH->waitCondVar(m_notifyCond, m_notifyMutex, -1);
m_bufferWaiting = false;
sendBuffer();
}
}
catch (XArch& e) {
@ -178,9 +159,6 @@ IpcLogOutputter::bufferThread(void*)
void
IpcLogOutputter::notifyBuffer()
{
if (!m_bufferWaiting) {
return;
}
ArchMutexLock lock(m_notifyMutex);
ARCH->broadcastCondVar(m_notifyCond);
}
@ -206,8 +184,11 @@ IpcLogOutputter::getChunk(size_t count)
void
IpcLogOutputter::sendBuffer()
{
IpcLogLineMessage message(getChunk(kMaxSendLines));
if (m_buffer.empty() || !m_ipcServer.hasClients(kIpcClientGui)) {
return;
}
IpcLogLineMessage message(getChunk(kMaxSendLines));
m_sending = true;
m_ipcServer.send(message, kIpcClientGui);
m_sending = false;

29
src/lib/ipc/IpcLogOutputter.h
View File

@ -34,7 +34,12 @@ This outputter writes output to the GUI via IPC.
*/
class IpcLogOutputter : public ILogOutputter {
public:
IpcLogOutputter(IpcServer& ipcServer);
/*!
If \p useThread is \c true, the buffer will be sent using a thread.
If \p useThread is \c false, then the buffer needs to be sent manually
using the \c sendBuffer() function.
*/
IpcLogOutputter(IpcServer& ipcServer, bool useThread);
virtual ~IpcLogOutputter();
// ILogOutputter overrides
@ -46,30 +51,28 @@ public:
//! @name manipulators
//@{
//! Same as write, but allows message to sidestep anti-recursion mechanism.
bool write(ELevel level, const char* text, bool force);
//! Notify that the buffer should be sent.
void notifyBuffer();
//! Set the buffer size.
//! Set the buffer size
/*!
Set the maximum size of the buffer to protect memory
from runaway logging.
*/
void bufferMaxSize(UInt16 bufferMaxSize);
//! Wait for empty buffer
/*!
Wait on a cond var until the buffer is empty.
*/
void waitForEmpty();
//! Set the buffer size.
//! Set the rate limit
/*!
Set the maximum number of \p writeRate for every \p timeRate in seconds.
*/
void bufferRateLimit(UInt16 writeLimit, double timeLimit);
//! Send the buffer
/*!
Sends a chunk of the buffer to the IPC server, normally called
when threaded mode is on.
*/
void sendBuffer();
//@}
@ -88,7 +91,6 @@ private:
void init();
void bufferThread(void*);
String getChunk(size_t count);
void sendBuffer();
void appendBuffer(const String& text);
private:
@ -110,4 +112,5 @@ private:
double m_bufferRateTimeLimit;
UInt16 m_bufferWriteCount;
double m_bufferRateStart;
bool m_useThread;
};

4
src/lib/platform/MSWindowsWatchdog.cpp
View File

@ -420,9 +420,7 @@ MSWindowsWatchdog::outputLoop(void*)
testOutput(buffer);
// send process output over IPC to GUI, and force it to be sent
// which bypasses the ipc logging anti-recursion mechanism.
m_ipcLogOutputter.write(kINFO, buffer, true);
m_ipcLogOutputter.write(kINFO, buffer);
if (m_fileLogOutputter != NULL) {
m_fileLogOutputter->write(kINFO, buffer);

2
src/lib/synergy/DaemonApp.cpp
View File

@ -211,7 +211,7 @@ DaemonApp::mainLoop(bool logToFile)
m_ipcServer = new IpcServer(m_events, &multiplexer);
// send logging to gui via ipc, log system adopts outputter.
m_ipcLogOutputter = new IpcLogOutputter(*m_ipcServer);
m_ipcLogOutputter = new IpcLogOutputter(*m_ipcServer, true);
CLOG->insert(m_ipcLogOutputter);
#if SYSAPI_WIN32

2
src/test/mock/ipc/MockIpcServer.h
View File

@ -44,7 +44,7 @@ public:
}
void waitForSend() {
ARCH->waitCondVar(m_sendCond, m_sendMutex, -1);
ARCH->waitCondVar(m_sendCond, m_sendMutex, 5);
}
private:

110
src/test/unittests/ipc/IpcLogOutputterTests.cpp
View File

@ -45,76 +45,90 @@ inline const Matcher<const IpcMessage&> IpcLogLineMessageEq(const String& s) {
return MatcherCast<const IpcMessage&>(m);
}
TEST(IpcLogOutputterTests, write_overBufferMaxSize_firstLineTruncated)
{
MockIpcServer mockServer;
mockServer.delegateToFake();
ON_CALL(mockServer, hasClients(_)).WillByDefault(Return(true));
EXPECT_CALL(mockServer, hasClients(_)).Times(1);
EXPECT_CALL(mockServer, send(IpcLogLineMessageEq("mock 2\nmock 3\n"), _)).Times(1);
IpcLogOutputter outputter(mockServer);
outputter.bufferMaxSize(2);
// log more lines than the buffer can contain
outputter.write(kNOTE, "mock 1");
outputter.write(kNOTE, "mock 2");
outputter.write(kNOTE, "mock 3");
mockServer.waitForSend();
}
TEST(IpcLogOutputterTests, write_underBufferMaxSize_allLinesAreSent)
{
MockIpcServer mockServer;
mockServer.delegateToFake();
ON_CALL(mockServer, hasClients(_)).WillByDefault(Return(true));
EXPECT_CALL(mockServer, hasClients(_)).Times(1);
EXPECT_CALL(mockServer, send(IpcLogLineMessageEq("mock 1\nmock 2\n"), _)).Times(1);
IpcLogOutputter outputter(mockServer);
outputter.bufferMaxSize(2);
// log more lines than the buffer can contain
outputter.write(kNOTE, "mock 1");
outputter.write(kNOTE, "mock 2");
mockServer.waitForSend();
}
TEST(IpcLogOutputterTests, write_overBufferRateLimit_lastLineTruncated)
TEST(IpcLogOutputterTests, write_threadingEnabled_bufferIsSent)
{
MockIpcServer mockServer;
mockServer.delegateToFake();
ON_CALL(mockServer, hasClients(_)).WillByDefault(Return(true));
EXPECT_CALL(mockServer, hasClients(_)).Times(2);
EXPECT_CALL(mockServer, send(IpcLogLineMessageEq("mock 1\n"), _)).Times(1);
EXPECT_CALL(mockServer, send(IpcLogLineMessageEq("mock 2\n"), _)).Times(1);
IpcLogOutputter outputter(mockServer, true);
outputter.write(kNOTE, "mock 1");
mockServer.waitForSend();
outputter.write(kNOTE, "mock 2");
mockServer.waitForSend();
}
TEST(IpcLogOutputterTests, write_overBufferMaxSize_firstLineTruncated)
{
MockIpcServer mockServer;
ON_CALL(mockServer, hasClients(_)).WillByDefault(Return(true));
EXPECT_CALL(mockServer, hasClients(_)).Times(1);
EXPECT_CALL(mockServer, send(IpcLogLineMessageEq("mock 2\nmock 3\n"), _)).Times(1);
IpcLogOutputter outputter(mockServer, false);
outputter.bufferMaxSize(2);
// log more lines than the buffer can contain
outputter.write(kNOTE, "mock 1");
outputter.write(kNOTE, "mock 2");
outputter.write(kNOTE, "mock 3");
outputter.sendBuffer();
}
TEST(IpcLogOutputterTests, write_underBufferMaxSize_allLinesAreSent)
{
MockIpcServer mockServer;
ON_CALL(mockServer, hasClients(_)).WillByDefault(Return(true));
EXPECT_CALL(mockServer, hasClients(_)).Times(1);
EXPECT_CALL(mockServer, send(IpcLogLineMessageEq("mock 1\nmock 2\n"), _)).Times(1);
IpcLogOutputter outputter(mockServer, false);
outputter.bufferMaxSize(2);
// log more lines than the buffer can contain
outputter.write(kNOTE, "mock 1");
outputter.write(kNOTE, "mock 2");
outputter.sendBuffer();
}
TEST(IpcLogOutputterTests, write_overBufferRateLimit_lastLineTruncated)
{
MockIpcServer mockServer;
ON_CALL(mockServer, hasClients(_)).WillByDefault(Return(true));
EXPECT_CALL(mockServer, hasClients(_)).Times(2);
EXPECT_CALL(mockServer, send(IpcLogLineMessageEq("mock 1\n"), _)).Times(1);
EXPECT_CALL(mockServer, send(IpcLogLineMessageEq("mock 3\n"), _)).Times(1);
IpcLogOutputter outputter(mockServer);
IpcLogOutputter outputter(mockServer, false);
outputter.bufferRateLimit(1, 0.001); // 1ms
// log 1 more line than the buffer can accept in time limit.
outputter.write(kNOTE, "mock 1");
outputter.write(kNOTE, "mock 2");
mockServer.waitForSend();
outputter.sendBuffer();
// after waiting the time limit send another to make sure
// we can log after the time limit passes.
ARCH->sleep(0.002); // 2ms
ARCH->sleep(0.01); // 10ms
outputter.write(kNOTE, "mock 3");
outputter.write(kNOTE, "mock 4");
mockServer.waitForSend();
outputter.sendBuffer();
}
TEST(IpcLogOutputterTests, write_underBufferRateLimit_allLinesAreSent)
{
MockIpcServer mockServer;
mockServer.delegateToFake();
ON_CALL(mockServer, hasClients(_)).WillByDefault(Return(true));
@ -122,19 +136,19 @@ TEST(IpcLogOutputterTests, write_underBufferRateLimit_allLinesAreSent)
EXPECT_CALL(mockServer, send(IpcLogLineMessageEq("mock 1\nmock 2\n"), _)).Times(1);
EXPECT_CALL(mockServer, send(IpcLogLineMessageEq("mock 3\nmock 4\n"), _)).Times(1);
IpcLogOutputter outputter(mockServer);
IpcLogOutputter outputter(mockServer, false);
outputter.bufferRateLimit(4, 1); // 1s (should be plenty of time)
// log 1 more line than the buffer can accept in time limit.
outputter.write(kNOTE, "mock 1");
outputter.write(kNOTE, "mock 2");
mockServer.waitForSend();
outputter.sendBuffer();
// after waiting the time limit send another to make sure
// we can log after the time limit passes.
outputter.write(kNOTE, "mock 3");
outputter.write(kNOTE, "mock 4");
mockServer.waitForSend();
outputter.sendBuffer();
}
#endif // WINAPI_MSWINDOWS