(Temp) Add debug traces to find out why test-cases fail

Author: jschmidt-icinga

lib/perfdata/perfdatawriterconnection.cpp

@@ -30,8 +30,10 @@ void PerfdataWriterConnection::Send(boost::asio::const_buffer data)
 
 	IoEngine::SpawnCoroutine(
 		m_Strand, [&, keepAlive = PerfdataWriterConnection::Ptr(this)](boost::asio::yield_context yc) {
+			Log(LogDebug, "PerfdataWriterConnection") << "Send()::1";
 			try {
 				EnsureConnected(yc);
+				Log(LogDebug, "PerfdataWriterConnection") << "Send()::2";
 
 				std::visit(
 					[&](auto& stream) {
@@ -40,9 +42,11 @@ void PerfdataWriterConnection::Send(boost::asio::const_buffer data)
 					},
 					m_Stream
 				);
+				Log(LogDebug, "PerfdataWriterConnection") << "Send()::3";
 
 				promise.set_value();
 			} catch (const std::exception&) {
+				Log(LogDebug, "PerfdataWriterConnection") << "Send()::E";
 				promise.set_exception(std::current_exception());
 			}
 		}
@@ -99,6 +103,7 @@ void PerfdataWriterConnection::StartDisconnectTimeout(std::chrono::milliseconds
 	IoEngine::SpawnCoroutine(
 		m_Strand, [&, timeout, keepAlive = PerfdataWriterConnection::Ptr(this)](boost::asio::yield_context yc) {
 			try {
+				Log(LogDebug, "PerfdataWriterConnection") << "StartDisconnectTimeout()::1";
 				// Is this even needed?
 				if (m_State == State::stopped) {
 					return;
@@ -108,9 +113,11 @@ void PerfdataWriterConnection::StartDisconnectTimeout(std::chrono::milliseconds
 					m_State = State::stopped;
 				}
 
+				Log(LogDebug, "PerfdataWriterConnection") << "StartDisconnectTimeout()::2";
 				m_DisconnectTimer.expires_after(timeout);
 				m_DisconnectTimer.async_wait(yc);
 
+				Log(LogDebug, "PerfdataWriterConnection") << "StartDisconnectTimeout()::3";
 				/* There may be ongoing connect or disconnect events, in which case
 				 * we will want to wait until those are complete and we're in a defined
 				 * state again.
@@ -119,18 +126,26 @@ void PerfdataWriterConnection::StartDisconnectTimeout(std::chrono::milliseconds
 				 * connection idles after SSL handshake has started (or before).
 				 */
 				while (m_State == State::connecting || m_State == State::disconnecting) {
+					Log(LogDebug, "PerfdataWriterConnection") << "StartDisconnectTimeout()::3.1";
+					std::visit([](auto& stream) { stream->lowest_layer().cancel(); }, m_Stream);
 					m_DisconnectTimer.expires_after(10ms);
 					m_DisconnectTimer.async_wait(yc);
 				}
 
+				Log(LogDebug, "PerfdataWriterConnection") << "StartDisconnectTimeout()::4";
+
 				m_State = State::stopped;
 				std::visit([](auto& stream) { stream->lowest_layer().cancel(); }, m_Stream);
 
+				Log(LogDebug, "PerfdataWriterConnection") << "StartDisconnectTimeout()::5";
 				// Yield to give the other coroutine a chance to throw.
 				boost::asio::post(yc);
 
+				Log(LogDebug, "PerfdataWriterConnection") << "StartDisconnectTimeout()::6";
 				if (m_State == State::connected) {
+					Log(LogDebug, "PerfdataWriterConnection") << "StartDisconnectTimeout()::6.1";
 					Disconnect(yc);
+					Log(LogDebug, "PerfdataWriterConnection") << "StartDisconnectTimeout()::6.2";
 				}
 			} catch (const std::exception& ex) {
 				Log(LogCritical, "PerfdataWriterConnection") << "Ex during disconnect timeout: " << ex.what();
@@ -154,7 +169,9 @@ PerfdataWriterConnection::Stream PerfdataWriterConnection::ResetStream()
 void PerfdataWriterConnection::EnsureConnected(boost::asio::yield_context yc)
 {
 	while (m_State != State::connected) {
+		Log(LogDebug, "PerfdataWriterConnection") << "EnsureConnected()::1";
 		if (m_State == State::stopped) {
+			Log(LogDebug, "PerfdataWriterConnection") << "EnsureConnected()::1.1";
 			const boost::system::error_code ec{
 				boost::system::errc::operation_canceled, boost::system::system_category()
 			};
@@ -164,26 +181,34 @@ void PerfdataWriterConnection::EnsureConnected(boost::asio::yield_context yc)
 		m_State = State::connecting;
 
 		try {
+			Log(LogDebug, "PerfdataWriterConnection") << "EnsureConnected()::2";
 			std::visit(
 				[&](auto& stream) {
+					Log(LogDebug, "PerfdataWriterConnection") << "EnsureConnected()::3";
 					::Connect(stream->lowest_layer(), m_Host, m_Port, yc);
-
+					Log(LogDebug, "PerfdataWriterConnection") << "EnsureConnected()::4";
 					if constexpr (std::is_same_v<std::decay_t<decltype(stream)>, TlsStream>) {
+						Log(LogDebug, "PerfdataWriterConnection") << "EnsureConnected()::4.1";
 						using type = boost::asio::ssl::stream_base::handshake_type;
 
 						stream->next_layer().async_handshake(type::client, yc);
+						Log(LogDebug, "PerfdataWriterConnection") << "EnsureConnected()::4.2";
 
 						if (m_VerifySecure && !stream->next_layer().IsVerifyOK()) {
 							BOOST_THROW_EXCEPTION(std::runtime_error{"TLS certificate validation failed"});
+							Log(LogDebug, "PerfdataWriterConnection") << "EnsureConnected()::4.2.1";
 						}
 					}
 				},
 				m_Stream
 			);
 
 			m_State = State::connected;
+			Log(LogDebug, "PerfdataWriterConnection") << "EnsureConnected()::5";
 		} catch (const std::exception& ex) {
+			Log(LogDebug, "PerfdataWriterConnection") << "EnsureConnected()::E: " << ex.what();
 			if (m_State == State::connecting) {
+				Log(LogDebug, "PerfdataWriterConnection") << "EnsureConnected()::E.1";
 				if (const auto* se = dynamic_cast<const boost::system::system_error*>(&ex);
 					se->code() == boost::system::errc::operation_canceled) {
 
@@ -206,6 +231,7 @@ void PerfdataWriterConnection::EnsureConnected(boost::asio::yield_context yc)
 void PerfdataWriterConnection::Disconnect(boost::asio::yield_context yc)
 {
 	if (m_State == State::connected) {
+		Log(LogDebug, "PerfdataWriterConnection") << "disconnecting";
 		m_State = State::disconnecting;
 
 		if (std::holds_alternative<Shared<AsioTlsStream>::Ptr>(m_Stream)) {