[logging-log4cxx] branch master updated: LOGCXX-537 avoid deadlock if socket fails (#82)

[rm...@apache.org]

This is an automated email from the ASF dual-hosted git repository.

rmiddleton pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/logging-log4cxx.git


The following commit(s) were added to refs/heads/master by this push:
     new b213a62  LOGCXX-537 avoid deadlock if socket fails (#82)
b213a62 is described below

commit b213a62361ed8b797d3a7de26ccc0c1c1e9774a5
Author: Robert Middleton <rm...@users.noreply.github.com>
AuthorDate: Mon Dec 20 21:32:39 2021 -0500

    LOGCXX-537 avoid deadlock if socket fails (#82)
    
    * LOGCXX-537 Changed to recursive mutex, and ensure that we don't wait too long for connections
    
    * added and then removed test that seems to deadlock sometimes
---
 src/main/cpp/appenderskeleton.cpp           | 14 ++++-----
 src/main/cpp/asyncappender.cpp              |  2 +-
 src/main/cpp/fileappender.cpp               | 26 +++++++--------
 src/main/cpp/rollingfileappender.cpp        |  4 +--
 src/main/cpp/socketappender.cpp             |  2 +-
 src/main/cpp/socketappenderskeleton.cpp     | 24 ++++++++------
 src/main/cpp/sockethubappender.cpp          |  6 ++--
 src/main/cpp/telnetappender.cpp             | 10 +++---
 src/main/cpp/writerappender.cpp             |  4 +--
 src/main/cpp/xmlsocketappender.cpp          |  2 +-
 src/main/include/log4cxx/appenderskeleton.h |  2 +-
 src/test/cpp/net/socketappendertestcase.cpp | 49 +++++++++++++++++++++++++++++
 12 files changed, 99 insertions(+), 46 deletions(-)

diff --git a/src/main/cpp/appenderskeleton.cpp b/src/main/cpp/appenderskeleton.cpp
index 6df2551..0705c6e 100644
--- a/src/main/cpp/appenderskeleton.cpp
+++ b/src/main/cpp/appenderskeleton.cpp
@@ -39,7 +39,7 @@ AppenderSkeleton::AppenderSkeleton()
 		tailFilter(),
 		pool()
 {
-	std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
 	closed = false;
 }
 
@@ -52,7 +52,7 @@ AppenderSkeleton::AppenderSkeleton(const LayoutPtr& layout1)
 	  tailFilter(),
 	  pool()
 {
-	std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
 	closed = false;
 }
 
@@ -70,7 +70,7 @@ void AppenderSkeleton::finalize()
 
 void AppenderSkeleton::addFilter(const spi::FilterPtr& newFilter)
 {
-	std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
 
 	if (headFilter == 0)
 	{
@@ -85,7 +85,7 @@ void AppenderSkeleton::addFilter(const spi::FilterPtr& newFilter)
 
 void AppenderSkeleton::clearFilters()
 {
-	std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
 	headFilter = tailFilter = 0;
 }
 
@@ -96,7 +96,7 @@ bool AppenderSkeleton::isAsSevereAsThreshold(const LevelPtr& level) const
 
 void AppenderSkeleton::doAppend(const spi::LoggingEventPtr& event, Pool& pool1)
 {
-	std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
 
 	doAppendImpl(event, pool1);
 }
@@ -139,7 +139,7 @@ void AppenderSkeleton::doAppendImpl(const spi::LoggingEventPtr& event, Pool& poo
 
 void AppenderSkeleton::setErrorHandler(const spi::ErrorHandlerPtr errorHandler1)
 {
-	std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
 
 	if (errorHandler1 == 0)
 	{
@@ -155,7 +155,7 @@ void AppenderSkeleton::setErrorHandler(const spi::ErrorHandlerPtr errorHandler1)
 
 void AppenderSkeleton::setThreshold(const LevelPtr& threshold1)
 {
-	std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
 	this->threshold = threshold1;
 }
 
diff --git a/src/main/cpp/asyncappender.cpp b/src/main/cpp/asyncappender.cpp
index d357ff0..876c257 100644
--- a/src/main/cpp/asyncappender.cpp
+++ b/src/main/cpp/asyncappender.cpp
@@ -92,7 +92,7 @@ void AsyncAppender::setOption(const LogString& option,
 
 void AsyncAppender::doAppend(const spi::LoggingEventPtr& event, Pool& pool1)
 {
-	std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
 
 	doAppendImpl(event, pool1);
 }
diff --git a/src/main/cpp/fileappender.cpp b/src/main/cpp/fileappender.cpp
index cca1abb..e04d730 100644
--- a/src/main/cpp/fileappender.cpp
+++ b/src/main/cpp/fileappender.cpp
@@ -36,7 +36,7 @@ IMPLEMENT_LOG4CXX_OBJECT(FileAppender)
 
 FileAppender::FileAppender()
 {
-	std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
 	fileAppend = true;
 	bufferedIO = false;
 	bufferSize = 8 * 1024;
@@ -47,7 +47,7 @@ FileAppender::FileAppender(const LayoutPtr& layout1, const LogString& fileName1,
 	: WriterAppender(layout1)
 {
 	{
-		std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+		std::lock_guard<std::recursive_mutex> lock(mutex);
 		fileAppend = append1;
 		fileName = fileName1;
 		bufferedIO = bufferedIO1;
@@ -62,7 +62,7 @@ FileAppender::FileAppender(const LayoutPtr& layout1, const LogString& fileName1,
 	: WriterAppender(layout1)
 {
 	{
-		std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+		std::lock_guard<std::recursive_mutex> lock(mutex);
 		fileAppend = append1;
 		fileName = fileName1;
 		bufferedIO = false;
@@ -76,7 +76,7 @@ FileAppender::FileAppender(const LayoutPtr& layout1, const LogString& fileName1)
 	: WriterAppender(layout1)
 {
 	{
-		std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+		std::lock_guard<std::recursive_mutex> lock(mutex);
 		fileAppend = true;
 		fileName = fileName1;
 		bufferedIO = false;
@@ -93,13 +93,13 @@ FileAppender::~FileAppender()
 
 void FileAppender::setAppend(bool fileAppend1)
 {
-	std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
 	this->fileAppend = fileAppend1;
 }
 
 void FileAppender::setFile(const LogString& file)
 {
-	std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
 	setFileInternal(file);
 }
 
@@ -110,7 +110,7 @@ void FileAppender::setFileInternal(const LogString& file)
 
 void FileAppender::setBufferedIO(bool bufferedIO1)
 {
-	std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
 	this->bufferedIO = bufferedIO1;
 
 	if (bufferedIO1)
@@ -125,27 +125,27 @@ void FileAppender::setOption(const LogString& option,
 	if (StringHelper::equalsIgnoreCase(option, LOG4CXX_STR("FILE"), LOG4CXX_STR("file"))
 		|| StringHelper::equalsIgnoreCase(option, LOG4CXX_STR("FILENAME"), LOG4CXX_STR("filename")))
 	{
-		std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+		std::lock_guard<std::recursive_mutex> lock(mutex);
 		fileName = stripDuplicateBackslashes(value);
 	}
 	else if (StringHelper::equalsIgnoreCase(option, LOG4CXX_STR("APPEND"), LOG4CXX_STR("append")))
 	{
-		std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+		std::lock_guard<std::recursive_mutex> lock(mutex);
 		fileAppend = OptionConverter::toBoolean(value, true);
 	}
 	else if (StringHelper::equalsIgnoreCase(option, LOG4CXX_STR("BUFFEREDIO"), LOG4CXX_STR("bufferedio")))
 	{
-		std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+		std::lock_guard<std::recursive_mutex> lock(mutex);
 		bufferedIO = OptionConverter::toBoolean(value, true);
 	}
 	else if (StringHelper::equalsIgnoreCase(option, LOG4CXX_STR("IMMEDIATEFLUSH"), LOG4CXX_STR("immediateflush")))
 	{
-		std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+		std::lock_guard<std::recursive_mutex> lock(mutex);
 		bufferedIO = !OptionConverter::toBoolean(value, false);
 	}
 	else if (StringHelper::equalsIgnoreCase(option, LOG4CXX_STR("BUFFERSIZE"), LOG4CXX_STR("buffersize")))
 	{
-		std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+		std::lock_guard<std::recursive_mutex> lock(mutex);
 		bufferSize = OptionConverter::toFileSize(value, 8 * 1024);
 	}
 	else
@@ -156,7 +156,7 @@ void FileAppender::setOption(const LogString& option,
 
 void FileAppender::activateOptions(Pool& p)
 {
-	std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
 	activateOptionsInternal(p);
 }
 
diff --git a/src/main/cpp/rollingfileappender.cpp b/src/main/cpp/rollingfileappender.cpp
index 7d236f4..48aad5f 100644
--- a/src/main/cpp/rollingfileappender.cpp
+++ b/src/main/cpp/rollingfileappender.cpp
@@ -94,7 +94,7 @@ void RollingFileAppenderSkeleton::activateOptions(Pool& p)
 	}
 
 	{
-		std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+		std::lock_guard<std::recursive_mutex> lock(mutex);
 		triggeringPolicy->activateOptions(p);
 		rollingPolicy->activateOptions(p);
 
@@ -183,7 +183,7 @@ void RollingFileAppenderSkeleton::releaseFileLock(apr_file_t* lock_file)
  */
 bool RollingFileAppenderSkeleton::rollover(Pool& p)
 {
-	std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
 	return rolloverInternal(p);
 }
 
diff --git a/src/main/cpp/socketappender.cpp b/src/main/cpp/socketappender.cpp
index 57f8ade..4809a35 100644
--- a/src/main/cpp/socketappender.cpp
+++ b/src/main/cpp/socketappender.cpp
@@ -78,7 +78,7 @@ int SocketAppender::getDefaultPort() const
 
 void SocketAppender::setSocket(log4cxx::helpers::SocketPtr& socket, Pool& p)
 {
-	std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
 
 	SocketOutputStreamPtr sock = SocketOutputStreamPtr(new SocketOutputStream(socket));
 	oos = ObjectOutputStreamPtr(new ObjectOutputStream(sock, p));
diff --git a/src/main/cpp/socketappenderskeleton.cpp b/src/main/cpp/socketappenderskeleton.cpp
index e3e1375..b0b73b4 100644
--- a/src/main/cpp/socketappenderskeleton.cpp
+++ b/src/main/cpp/socketappenderskeleton.cpp
@@ -78,7 +78,7 @@ void SocketAppenderSkeleton::activateOptions(Pool& p)
 
 void SocketAppenderSkeleton::close()
 {
-	std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
 
 	if (closed)
 	{
@@ -157,7 +157,14 @@ void SocketAppenderSkeleton::setOption(const LogString& option, const LogString&
 
 void SocketAppenderSkeleton::fireConnector()
 {
-	std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
+
+	if( thread.joinable() ){
+		// This should only get called if the thread has already exited.
+		// We could have a potential bug if fireConnector is called while
+		// the thread is waiting for a connection
+		thread.join();
+	}
 
 	if ( !thread.joinable() )
 	{
@@ -176,12 +183,6 @@ void SocketAppenderSkeleton::monitor()
 	{
 		try
 		{
-			std::this_thread::sleep_for( std::chrono::milliseconds( reconnectionDelay ) );
-
-			std::unique_lock<std::mutex> lock( interrupt_mutex );
-			interrupt.wait_for( lock, std::chrono::milliseconds( reconnectionDelay ),
-				std::bind(&SocketAppenderSkeleton::is_closed, this) );
-
 			if (!closed)
 			{
 				LogLog::debug(LogString(LOG4CXX_STR("Attempting connection to "))
@@ -190,9 +191,8 @@ void SocketAppenderSkeleton::monitor()
 				Pool p;
 				setSocket(socket, p);
 				LogLog::debug(LOG4CXX_STR("Connection established. Exiting connector thread."));
+				return;
 			}
-
-			return;
 		}
 		catch (InterruptedException&)
 		{
@@ -216,6 +216,10 @@ void SocketAppenderSkeleton::monitor()
 				+ exmsg);
 		}
 
+		std::unique_lock<std::mutex> lock( interrupt_mutex );
+		interrupt.wait_for( lock, std::chrono::milliseconds( reconnectionDelay ),
+			std::bind(&SocketAppenderSkeleton::is_closed, this) );
+
 		isClosed = closed;
 	}
 
diff --git a/src/main/cpp/sockethubappender.cpp b/src/main/cpp/sockethubappender.cpp
index 7d83a23..6a8a0aa 100644
--- a/src/main/cpp/sockethubappender.cpp
+++ b/src/main/cpp/sockethubappender.cpp
@@ -84,7 +84,7 @@ void SocketHubAppender::setOption(const LogString& option,
 void SocketHubAppender::close()
 {
 	{
-		std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+		std::lock_guard<std::recursive_mutex> lock(mutex);
 
 		if (closed)
 		{
@@ -104,7 +104,7 @@ void SocketHubAppender::close()
 		thread.join();
 	}
 
-	std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
 	// close all of the connections
 	LogLog::debug(LOG4CXX_STR("closing client connections"));
 
@@ -234,7 +234,7 @@ void SocketHubAppender::monitor()
 					+ LOG4CXX_STR(")"));
 
 				// add it to the oosList.
-				std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+				std::lock_guard<std::recursive_mutex> lock(mutex);
 				OutputStreamPtr os(new SocketOutputStream(socket));
 				Pool p;
 				ObjectOutputStreamPtr oos(new ObjectOutputStream(os, p));
diff --git a/src/main/cpp/telnetappender.cpp b/src/main/cpp/telnetappender.cpp
index 9087242..2a880ee 100644
--- a/src/main/cpp/telnetappender.cpp
+++ b/src/main/cpp/telnetappender.cpp
@@ -84,13 +84,13 @@ void TelnetAppender::setOption(const LogString& option,
 
 LogString TelnetAppender::getEncoding() const
 {
-	log4cxx::shared_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
 	return encoding;
 }
 
 void TelnetAppender::setEncoding(const LogString& value)
 {
-	std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
 	encoder = CharsetEncoder::getEncoder(value);
 	encoding = value;
 }
@@ -98,7 +98,7 @@ void TelnetAppender::setEncoding(const LogString& value)
 
 void TelnetAppender::close()
 {
-	std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
 
 	if (closed)
 	{
@@ -195,7 +195,7 @@ void TelnetAppender::append(const spi::LoggingEventPtr& event, Pool& p)
 		LogString::const_iterator msgIter(msg.begin());
 		ByteBuffer buf(bytes, bytesSize);
 
-		log4cxx::shared_lock<log4cxx::shared_mutex> lock(mutex);
+		std::lock_guard<std::recursive_mutex> lock(mutex);
 
 		while (msgIter != msg.end())
 		{
@@ -251,7 +251,7 @@ void TelnetAppender::acceptConnections()
 				//
 				//   find unoccupied connection
 				//
-				std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+				std::lock_guard<std::recursive_mutex> lock(mutex);
 
 				for (ConnectionList::iterator iter = connections.begin();
 					iter != connections.end();
diff --git a/src/main/cpp/writerappender.cpp b/src/main/cpp/writerappender.cpp
index 57996f5..1d4303d 100644
--- a/src/main/cpp/writerappender.cpp
+++ b/src/main/cpp/writerappender.cpp
@@ -151,7 +151,7 @@ bool WriterAppender::checkEntryConditions() const
    */
 void WriterAppender::close()
 {
-	std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
 
 	if (closed)
 	{
@@ -278,7 +278,7 @@ void WriterAppender::writeHeader(Pool& p)
 
 void WriterAppender::setWriter(const WriterPtr& newWriter)
 {
-	std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
 	setWriterInternal(newWriter);
 }
 
diff --git a/src/main/cpp/xmlsocketappender.cpp b/src/main/cpp/xmlsocketappender.cpp
index d5b9942..36fdfce 100644
--- a/src/main/cpp/xmlsocketappender.cpp
+++ b/src/main/cpp/xmlsocketappender.cpp
@@ -84,7 +84,7 @@ void XMLSocketAppender::setSocket(log4cxx::helpers::SocketPtr& socket, Pool& p)
 {
 	OutputStreamPtr os(new SocketOutputStream(socket));
 	CharsetEncoderPtr charset(CharsetEncoder::getUTF8Encoder());
-	std::unique_lock<log4cxx::shared_mutex> lock(mutex);
+	std::lock_guard<std::recursive_mutex> lock(mutex);
 	writer = OutputStreamWriterPtr(new OutputStreamWriter(os, charset));
 }
 
diff --git a/src/main/include/log4cxx/appenderskeleton.h b/src/main/include/log4cxx/appenderskeleton.h
index b89b09e..3b7af8b 100644
--- a/src/main/include/log4cxx/appenderskeleton.h
+++ b/src/main/include/log4cxx/appenderskeleton.h
@@ -74,7 +74,7 @@ class LOG4CXX_EXPORT AppenderSkeleton :
 		bool closed;
 
 		log4cxx::helpers::Pool pool;
-		mutable log4cxx::shared_mutex mutex;
+		mutable std::recursive_mutex mutex;
 
 		/**
 		Subclasses of <code>AppenderSkeleton</code> should implement this
diff --git a/src/test/cpp/net/socketappendertestcase.cpp b/src/test/cpp/net/socketappendertestcase.cpp
index fe3753c..fe5c8e0 100644
--- a/src/test/cpp/net/socketappendertestcase.cpp
+++ b/src/test/cpp/net/socketappendertestcase.cpp
@@ -16,6 +16,9 @@
  */
 
 #include <log4cxx/net/socketappender.h>
+#include <log4cxx/patternlayout.h>
+#include <log4cxx/basicconfigurator.h>
+#include <log4cxx/helpers/serversocket.h>
 #include "../appenderskeletontestcase.h"
 #include "apr.h"
 
@@ -34,16 +37,62 @@ class SocketAppenderTestCase : public AppenderSkeletonTestCase
 		//
 		LOGUNIT_TEST(testDefaultThreshold);
 		LOGUNIT_TEST(testSetOptionThreshold);
+		LOGUNIT_TEST(testInvalidHost);
 
 		LOGUNIT_TEST_SUITE_END();
 
 
 	public:
 
+		void setUp()
+		{
+		}
+
+		void tearDown()
+		{
+			BasicConfigurator::resetConfiguration();
+		}
+
 		AppenderSkeleton* createAppenderSkeleton() const
 		{
 			return new log4cxx::net::SocketAppender();
 		}
+
+		void testInvalidHost(){
+//			log4cxx::net::SocketAppenderPtr appender = std::make_shared<log4cxx::net::SocketAppender>();
+//			log4cxx::PatternLayoutPtr layout = std::make_shared<log4cxx::PatternLayout>(LOG4CXX_STR("%m%n"));
+
+//			log4cxx::helpers::ServerSocket serverSocket(4445);
+
+//			appender->setLayout(layout);
+//			appender->setRemoteHost(LOG4CXX_STR("localhost"));
+//			appender->setReconnectionDelay(1);
+//			appender->setPort(4445);
+//			log4cxx::helpers::Pool pool;
+//			appender->activateOptions(pool);
+
+//			BasicConfigurator::configure(appender);
+
+//			log4cxx::Logger::getRootLogger()->setLevel(log4cxx::Level::getAll());
+
+//			std::thread th1( [](){
+//				for( int x = 0; x < 3000; x++ ){
+//					LOG4CXX_INFO(Logger::getLogger(LOG4CXX_STR("test")), "Some message" );
+//				}
+//			});
+//			std::thread th2( [](){
+//				for( int x = 0; x < 3000; x++ ){
+//					LOG4CXX_INFO(Logger::getLogger(LOG4CXX_STR("test")), "Some message" );
+//				}
+//			});
+
+//			SocketPtr incomingSocket = serverSocket.accept();
+//			incomingSocket->close();
+
+//			// If we do not get here, we have deadlocked
+//			th1.join();
+//			th2.join();
+		}
 };
 
 LOGUNIT_TEST_SUITE_REGISTRATION(SocketAppenderTestCase);