diff --git a/plugin-unix.diff b/plugin-unix.diff deleted file mode 100644 index e6e39633..00000000 --- a/plugin-unix.diff +++ /dev/null @@ -1,15 +0,0 @@ -diff --git a/src/lib/arch/unix/ArchPluginUnix.cpp b/src/lib/arch/unix/ArchPluginUnix.cpp -index 997c274..3e390f0 100644 ---- a/src/lib/arch/unix/ArchPluginUnix.cpp -+++ b/src/lib/arch/unix/ArchPluginUnix.cpp -@@ -76,8 +76,8 @@ ArchPluginUnix::load() - void* library = dlopen(path.c_str(), RTLD_LAZY); - - if (library == NULL) { -- LOG((CLOG_ERR "failed to load plugin: %s", (*it).c_str())); -- throw XArch(dlerror()); -+ LOG((CLOG_ERR "failed to load plugin '%s', error: %s", (*it).c_str(), dlerror())); -+ continue; - } - - String filename = synergy::string::removeFileExt(*it); diff --git a/src/gui/src/AppConfig.h b/src/gui/src/AppConfig.h index f9ed71c0..3a304b91 100644 --- a/src/gui/src/AppConfig.h +++ b/src/gui/src/AppConfig.h @@ -31,8 +31,10 @@ // 1: first version // 2: added language page // 3: added premium page and removed +// 4: ssl plugin 'ns' introduced +// 5: ssl plugin 'ns' updated // -const int kWizardVersion = 4; +const int kWizardVersion = 5; class QSettings; class SettingsDialog; diff --git a/src/lib/arch/unix/ArchPluginUnix.cpp b/src/lib/arch/unix/ArchPluginUnix.cpp index 997c2748..3e390f06 100644 --- a/src/lib/arch/unix/ArchPluginUnix.cpp +++ b/src/lib/arch/unix/ArchPluginUnix.cpp @@ -76,8 +76,8 @@ ArchPluginUnix::load() void* library = dlopen(path.c_str(), RTLD_LAZY); if (library == NULL) { - LOG((CLOG_ERR "failed to load plugin: %s", (*it).c_str())); - throw XArch(dlerror()); + LOG((CLOG_ERR "failed to load plugin '%s', error: %s", (*it).c_str(), dlerror())); + continue; } String filename = synergy::string::removeFileExt(*it); diff --git a/src/lib/ipc/IpcLogOutputter.cpp b/src/lib/ipc/IpcLogOutputter.cpp index 7474f655..6ce8d774 100644 --- a/src/lib/ipc/IpcLogOutputter.cpp +++ b/src/lib/ipc/IpcLogOutputter.cpp @@ -37,24 +37,25 @@ 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_bufferThread(nullptr), + m_running(false), m_notifyCond(ARCH->newCondVar()), m_notifyMutex(ARCH->newMutex()), m_bufferWaiting(false), m_bufferMaxSize(kBufferMaxSize), - m_bufferEmptyCond(ARCH->newCondVar()), - m_bufferEmptyMutex(ARCH->newMutex()), m_bufferRateWriteLimit(kBufferRateWriteLimit), m_bufferRateTimeLimit(kBufferRateTimeLimit), m_bufferWriteCount(0), m_bufferRateStart(ARCH->time()) { - m_bufferThread = new Thread(new TMethodJob( - this, &IpcLogOutputter::bufferThread)); + if (useThread) { + m_bufferThread = new Thread(new TMethodJob( + this, &IpcLogOutputter::bufferThread)); + } } IpcLogOutputter::~IpcLogOutputter() @@ -62,17 +63,13 @@ 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); - - ARCH->closeCondVar(m_bufferEmptyCond); - -#ifndef WINAPI_CARBON - // HACK: assert fails on mac debug, can't see why. - ARCH->closeMutex(m_bufferEmptyMutex); -#endif // WINAPI_CARBON } void @@ -83,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 @@ -94,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); @@ -152,34 +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(); - } - } - - // program may be stopping while we were in the send loop. - if (!m_running) { - break; - } - if (m_buffer.empty()) { - ArchMutexLock lock(m_bufferEmptyMutex); - ARCH->broadcastCondVar(m_bufferEmptyCond); + ArchMutexLock lock(m_notifyMutex); + ARCH->waitCondVar(m_notifyCond, m_notifyMutex, -1); } - m_bufferWaiting = true; - ARCH->waitCondVar(m_notifyCond, m_notifyMutex, -1); - m_bufferWaiting = false; + sendBuffer(); } } catch (XArch& e) { @@ -192,9 +159,6 @@ IpcLogOutputter::bufferThread(void*) void IpcLogOutputter::notifyBuffer() { - if (!m_bufferWaiting) { - return; - } ArchMutexLock lock(m_notifyMutex); ARCH->broadcastCondVar(m_notifyCond); } @@ -220,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; @@ -239,12 +206,6 @@ IpcLogOutputter::bufferMaxSize() const return m_bufferMaxSize; } -void -IpcLogOutputter::waitForEmpty() -{ - ARCH->waitCondVar(m_bufferEmptyCond, m_bufferEmptyMutex, -1); -} - void IpcLogOutputter::bufferRateLimit(UInt16 writeLimit, double timeLimit) { diff --git a/src/lib/ipc/IpcLogOutputter.h b/src/lib/ipc/IpcLogOutputter.h index 9b277a03..a6a476a6 100644 --- a/src/lib/ipc/IpcLogOutputter.h +++ b/src/lib/ipc/IpcLogOutputter.h @@ -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: @@ -106,10 +108,9 @@ private: IArchMultithread::ThreadID m_bufferThreadId; UInt16 m_bufferMaxSize; - ArchCond m_bufferEmptyCond; - ArchMutex m_bufferEmptyMutex; UInt16 m_bufferRateWriteLimit; double m_bufferRateTimeLimit; UInt16 m_bufferWriteCount; double m_bufferRateStart; + bool m_useThread; }; diff --git a/src/lib/platform/MSWindowsWatchdog.cpp b/src/lib/platform/MSWindowsWatchdog.cpp index a43c7194..8bbb0ab2 100644 --- a/src/lib/platform/MSWindowsWatchdog.cpp +++ b/src/lib/platform/MSWindowsWatchdog.cpp @@ -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); diff --git a/src/lib/plugin/ns/SecureSocket.cpp b/src/lib/plugin/ns/SecureSocket.cpp index ad75e3c4..f182ee8a 100644 --- a/src/lib/plugin/ns/SecureSocket.cpp +++ b/src/lib/plugin/ns/SecureSocket.cpp @@ -35,6 +35,7 @@ // #define MAX_ERROR_SIZE 65535 +#define MAX_RETRY_COUNT 60 static const char kFingerprintDirName[] = "SSL/Fingerprints"; //static const char kFingerprintLocalFilename[] = "Local.txt"; @@ -50,7 +51,8 @@ SecureSocket::SecureSocket( IEventQueue* events, SocketMultiplexer* socketMultiplexer) : TCPSocket(events, socketMultiplexer), - m_secureReady(false) + m_secureReady(false), + m_maxRetry(MAX_RETRY_COUNT) { } @@ -59,7 +61,8 @@ SecureSocket::SecureSocket( SocketMultiplexer* socketMultiplexer, ArchSocket socket) : TCPSocket(events, socketMultiplexer, socket), - m_secureReady(false) + m_secureReady(false), + m_maxRetry(MAX_RETRY_COUNT) { } @@ -111,7 +114,9 @@ SecureSocket::secureRead(void* buffer, UInt32 n) LOG((CLOG_DEBUG2 "reading secure socket")); r = SSL_read(m_ssl->m_ssl, buffer, n); - bool fatal, retry; + bool fatal; + static int retry; + checkResult(r, fatal, retry); if (retry) { @@ -130,7 +135,9 @@ SecureSocket::secureWrite(const void* buffer, UInt32 n) LOG((CLOG_DEBUG2 "writing secure socket")); r = SSL_write(m_ssl->m_ssl, buffer, n); - bool fatal, retry; + bool fatal; + static int retry; + checkResult(r, fatal, retry); if (retry) { @@ -253,7 +260,9 @@ SecureSocket::secureAccept(int socket) LOG((CLOG_DEBUG2 "accepting secure socket")); int r = SSL_accept(m_ssl->m_ssl); - bool fatal, retry; + bool fatal; + static int retry; + checkResult(r, fatal, retry); if (fatal) { @@ -263,12 +272,18 @@ SecureSocket::secureAccept(int socket) ARCH->sleep(1); } - m_secureReady = !retry; + if (retry == 0) { + m_secureReady = true; + } + else { + m_secureReady = false; + } + if (m_secureReady) { LOG((CLOG_INFO "accepted secure socket")); } - return retry; + return !m_secureReady; } bool @@ -282,7 +297,9 @@ SecureSocket::secureConnect(int socket) LOG((CLOG_DEBUG2 "connecting secure socket")); int r = SSL_connect(m_ssl->m_ssl); - bool fatal, retry; + bool fatal; + static int retry; + checkResult(r, fatal, retry); if (fatal) { @@ -291,7 +308,12 @@ SecureSocket::secureConnect(int socket) return false; } - m_secureReady = !retry; + if (retry == 0) { + m_secureReady = true; + } + else { + m_secureReady = false; + } if (m_secureReady) { if (verifyCertFingerprint()) { @@ -306,7 +328,7 @@ SecureSocket::secureConnect(int socket) } } - return retry; + return !m_secureReady; } bool @@ -332,22 +354,23 @@ SecureSocket::showCertificate() } void -SecureSocket::checkResult(int n, bool& fatal, bool& retry) +SecureSocket::checkResult(int n, bool& fatal, int& retry) { // ssl errors are a little quirky. the "want" errors are normal and // should result in a retry. fatal = false; - retry = false; int errorCode = SSL_get_error(m_ssl->m_ssl, n); switch (errorCode) { case SSL_ERROR_NONE: + retry = 0; // operation completed break; case SSL_ERROR_ZERO_RETURN: // connection closed + retry = 0; LOG((CLOG_DEBUG2 "SSL connection has been closed")); break; @@ -355,8 +378,17 @@ SecureSocket::checkResult(int n, bool& fatal, bool& retry) case SSL_ERROR_WANT_WRITE: case SSL_ERROR_WANT_CONNECT: case SSL_ERROR_WANT_ACCEPT: - LOG((CLOG_DEBUG2 "need to retry the same SSL function")); - retry = true; + retry += 1; + // If there are a lot of retrys, it's worth warning about + if ( retry % 5 == 0 ) { + LOG((CLOG_INFO "need to retry the same SSL function(%d) retry:%d", errorCode, retry)); + } + else if ( retry == (maxRetry() / 2) ) { + LOG((CLOG_WARN "need to retry the same SSL function(%d) retry:%d", errorCode, retry)); + } + else { + LOG((CLOG_DEBUG2 "need to retry the same SSL function(%d) retry:%d", errorCode, retry)); + } break; case SSL_ERROR_SYSCALL: @@ -390,7 +422,14 @@ SecureSocket::checkResult(int n, bool& fatal, bool& retry) break; } + // If the retry max would exceed the allowed, treat it as a fatal error + if (retry > maxRetry()) { + LOG((CLOG_ERR "Maximum retry count exceeded:%d",retry)); + fatal = true; + } + if (fatal) { + retry = 0; showError(); disconnect(); } diff --git a/src/lib/plugin/ns/SecureSocket.h b/src/lib/plugin/ns/SecureSocket.h index 72bc51db..754956ca 100644 --- a/src/lib/plugin/ns/SecureSocket.h +++ b/src/lib/plugin/ns/SecureSocket.h @@ -50,6 +50,8 @@ public: UInt32 secureWrite(const void* buffer, UInt32 n); void initSsl(bool server); bool loadCertificates(String& CertFile); + void maxRetry(int limit) { m_maxRetry = limit; }; + int maxRetry() const { return m_maxRetry; }; private: // SSL @@ -58,7 +60,7 @@ private: bool secureAccept(int s); bool secureConnect(int s); bool showCertificate(); - void checkResult(int n, bool& fatal, bool& retry); + void checkResult(int n, bool& fatal, int& retry); void showError(const char* reason = NULL); String getError(); void disconnect(); @@ -78,4 +80,5 @@ private: private: Ssl* m_ssl; bool m_secureReady; + int m_maxRetry; }; diff --git a/src/lib/synergy/DaemonApp.cpp b/src/lib/synergy/DaemonApp.cpp index 980dd54b..15ff14df 100644 --- a/src/lib/synergy/DaemonApp.cpp +++ b/src/lib/synergy/DaemonApp.cpp @@ -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 diff --git a/src/test/mock/ipc/MockIpcServer.h b/src/test/mock/ipc/MockIpcServer.h index ae63cd34..6500887b 100644 --- a/src/test/mock/ipc/MockIpcServer.h +++ b/src/test/mock/ipc/MockIpcServer.h @@ -19,17 +19,40 @@ #include "ipc/IpcServer.h" #include "ipc/IpcMessage.h" +#include "arch/Arch.h" #include "test/global/gmock.h" +using ::testing::_; +using ::testing::Invoke; + class IEventQueue; class MockIpcServer : public IpcServer { public: - MockIpcServer() { } + MockIpcServer() : + m_sendCond(ARCH->newCondVar()), + m_sendMutex(ARCH->newMutex()) { } MOCK_METHOD0(listen, void()); MOCK_METHOD2(send, void(const IpcMessage&, EIpcClientType)); MOCK_CONST_METHOD1(hasClients, bool(EIpcClientType)); + + void delegateToFake() { + ON_CALL(*this, send(_, _)).WillByDefault(Invoke(this, &MockIpcServer::mockSend)); + } + + void waitForSend() { + ARCH->waitCondVar(m_sendCond, m_sendMutex, 5); + } + +private: + void mockSend(const IpcMessage&, EIpcClientType) { + ArchMutexLock lock(m_sendMutex); + ARCH->broadcastCondVar(m_sendCond); + } + + ArchCond m_sendCond; + ArchMutex m_sendMutex; }; diff --git a/src/test/unittests/ipc/IpcLogOutputterTests.cpp b/src/test/unittests/ipc/IpcLogOutputterTests.cpp index 18f1eb21..254752c4 100644 --- a/src/test/unittests/ipc/IpcLogOutputterTests.cpp +++ b/src/test/unittests/ipc/IpcLogOutputterTests.cpp @@ -45,7 +45,25 @@ inline const Matcher IpcLogLineMessageEq(const String& s) { return MatcherCast(m); } -TEST(IpcLogOutputterTests, write_bufferSizeWrapping) +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; @@ -54,19 +72,35 @@ TEST(IpcLogOutputterTests, write_bufferSizeWrapping) EXPECT_CALL(mockServer, hasClients(_)).Times(1); EXPECT_CALL(mockServer, send(IpcLogLineMessageEq("mock 2\nmock 3\n"), _)).Times(1); - IpcLogOutputter outputter(mockServer); + 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"); - - // wait for the buffer to be empty (all lines sent to IPC) - outputter.waitForEmpty(); + outputter.sendBuffer(); } -TEST(IpcLogOutputterTests, write_bufferRateLimit) +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; @@ -76,20 +110,45 @@ TEST(IpcLogOutputterTests, write_bufferRateLimit) 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"); - outputter.waitForEmpty(); + outputter.sendBuffer(); // after waiting the time limit send another to make sure // we can log after the time limit passes. ARCH->sleep(0.01); // 10ms outputter.write(kNOTE, "mock 3"); outputter.write(kNOTE, "mock 4"); - outputter.waitForEmpty(); + outputter.sendBuffer(); +} + +TEST(IpcLogOutputterTests, write_underBufferRateLimit_allLinesAreSent) +{ + MockIpcServer mockServer; + + ON_CALL(mockServer, hasClients(_)).WillByDefault(Return(true)); + + EXPECT_CALL(mockServer, hasClients(_)).Times(2); + 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, 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"); + 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"); + outputter.sendBuffer(); } #endif // WINAPI_MSWINDOWS