Added rate limiting to IPC logging #4624

src/lib/ipc/IpcLogOutputter.cpp

@@ -32,7 +32,9 @@
 
 enum EIpcLogOutputter {
 	kBufferMaxSize = 1000,
-	kMaxSendLines = 100
+	kMaxSendLines = 100,
+	kBufferRateWriteLimit = 1000, // writes per kBufferRateTime
+	kBufferRateTimeLimit = 1 // seconds
 };
 
 IpcLogOutputter::IpcLogOutputter(IpcServer& ipcServer) :
@@ -45,7 +47,11 @@ IpcLogOutputter::IpcLogOutputter(IpcServer& ipcServer) :
 	m_bufferWaiting(false),
 	m_bufferMaxSize(kBufferMaxSize),
 	m_bufferEmptyCond(ARCH->newCondVar()),
-	m_bufferEmptyMutex(ARCH->newMutex())
+	m_bufferEmptyMutex(ARCH->newMutex()),
+	m_bufferRateWriteLimit(kBufferRateWriteLimit),
+	m_bufferRateTimeLimit(kBufferRateTimeLimit),
+	m_bufferWriteCount(0),
+	m_bufferRateStart(ARCH->time())
 {
 	m_bufferThread = new Thread(new TMethodJob<IpcLogOutputter>(
 		this, &IpcLogOutputter::bufferThread));
@@ -120,12 +126,27 @@ void
 IpcLogOutputter::appendBuffer(const String& text)
 {
 	ArchMutexLock lock(m_bufferMutex);
+
+	double elapsed = ARCH->time() - m_bufferRateStart;
+	if (elapsed < m_bufferRateTimeLimit) {
+		if (m_bufferWriteCount >= m_bufferRateWriteLimit) {
+			// discard the log line if we've logged too much.
+			return;
+		}
+	}
+	else {
+		m_bufferWriteCount = 0;
+		m_bufferRateStart = ARCH->time();
+	}
+
 	if (m_buffer.size() >= m_bufferMaxSize) {
 		// if the queue is exceeds size limit,
 		// throw away the oldest item
 		m_buffer.pop_front();
 	}
+
 	m_buffer.push_back(text);
+	m_bufferWriteCount++;
 }
 
 void
@@ -219,11 +240,14 @@ IpcLogOutputter::bufferMaxSize() const
 }
 
 void
-IpcLogOutputter::close(bool waitForEmpty)
+IpcLogOutputter::waitForEmpty()
 {
-	if (waitForEmpty) {
-		ARCH->waitCondVar(m_bufferEmptyCond, m_bufferEmptyMutex, -1);
-	}
-
-	close();
+	ARCH->waitCondVar(m_bufferEmptyCond, m_bufferEmptyMutex, -1);
+}
+
+void
+IpcLogOutputter::bufferRateLimit(UInt16 writeLimit, double timeLimit)
+{
+	m_bufferRateWriteLimit = writeLimit;
+	m_bufferRateTimeLimit = timeLimit;
 }

src/lib/ipc/IpcLogOutputter.h

@@ -59,12 +59,17 @@ public:
 	*/
 	void				bufferMaxSize(UInt16 bufferMaxSize);
 	
-	//! Close the outputter
+	//! Wait for empty buffer
 	/*!
-	Close the outputter.  If \p waitForEmpty is true, it will wait until
-	the buffer has been sent to the IPC server before closing.
+	Wait on a cond var until the buffer is empty.
 	*/
-	void				close(bool waitForEmpty);
+	void				waitForEmpty();
+
+	//! Set the buffer size.
+	/*!
+	Set the maximum number of \p writeRate for every \p timeRate in seconds.
+	*/
+	void				bufferRateLimit(UInt16 writeLimit, double timeLimit);
 	
 	//@}
 	
@@ -103,4 +108,8 @@ private:
 	UInt16				m_bufferMaxSize;
 	ArchCond			m_bufferEmptyCond;
 	ArchMutex			m_bufferEmptyMutex;
+	UInt16				m_bufferRateWriteLimit;
+	double				m_bufferRateTimeLimit;
+	UInt16				m_bufferWriteCount;
+	double				m_bufferRateStart;
 };

src/test/unittests/ipc/IpcLogOutputterTests.cpp

@@ -57,15 +57,37 @@ TEST(IpcLogOutputterTests, write_bufferSizeWrapping)
 	outputter.bufferMaxSize(2);
 
 	// log more lines than the buffer can contain
-	for (UInt8 i = 1; i <= 3; i++) {
-		String s = string::sprintf("mock %d", i);
-		outputter.write(kNOTE, s.c_str());
-	}
+	outputter.write(kNOTE, "mock 1");
+	outputter.write(kNOTE, "mock 2");
+	outputter.write(kNOTE, "mock 3");
 
-	// close, but wait until the buffer is empty.
-	outputter.close(true);
+	// wait for the buffer to be empty (all lines sent to IPC)
+	outputter.waitForEmpty();
+}
 
-	EXPECT_EQ(true, true);
+TEST(IpcLogOutputterTests, write_bufferRateLimit)
+{
+	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);
+	outputter.bufferRateLimit(1, 0.01); // 5ms
+
+	// log 1 more line than the buffer can accept in time limit.
+	outputter.write(kNOTE, "mock 1");
+	outputter.write(kNOTE, "mock 2");
+	outputter.waitForEmpty();
+	
+	// after waiting the time limit send another to make sure
+	// we can log after the time limit passes.
+	ARCH->sleep(0.001); // 10ms
+	outputter.write(kNOTE, "mock 3");
+	outputter.waitForEmpty();
 }
 
 #endif // WINAPI_CARBON