[core] improve logging

libfreerdp/core/capabilities.c

@@ -4302,10 +4302,7 @@ BOOL rdp_recv_get_active_header(rdpRdp* rdp, wStream* s, UINT16* pChannelId, UIN
 		if (securityFlags & SEC_ENCRYPT)
 		{
 			if (!rdp_decrypt(rdp, s, length, securityFlags))
-			{
-				WLog_ERR(TAG, "rdp_decrypt failed");
 				return FALSE;
-			}
 		}
 	}
 

libfreerdp/core/connection.c

@@ -972,6 +972,7 @@ BOOL rdp_client_skip_mcs_channel_join(rdpRdp* rdp)
 	for (UINT32 i = 0; i < mcs->channelCount; i++)
 	{
 		rdpMcsChannel* cur = &mcs->channels[i];
+		WLog_DBG(TAG, " %s [%" PRIu16 "]", cur->Name, cur->ChannelId);
 		cur->joined = TRUE;
 	}
 
@@ -1038,7 +1039,11 @@ BOOL rdp_client_connect_mcs_channel_join_confirm(rdpRdp* rdp, wStream* s)
 	else if ((mcs->messageChannelId != 0) && !mcs->messageChannelJoined)
 	{
 		if (channelId != mcs->messageChannelId)
+		{
+			WLog_ERR(TAG, "expected messageChannelId=%" PRIu16 ", got %" PRIu16,
+			         mcs->messageChannelId, channelId);
 			return FALSE;
+		}
 
 		mcs->messageChannelJoined = TRUE;
 
@@ -1092,15 +1097,16 @@ BOOL rdp_client_connect_auto_detect(rdpRdp* rdp, wStream* s)
 	WINPR_ASSERT(rdp);
 	WINPR_ASSERT(rdp->mcs);
 
+	const UINT16 messageChannelId = rdp->mcs->messageChannelId;
 	/* If the MCS message channel has been joined... */
-	if (rdp->mcs->messageChannelId != 0)
+	if (messageChannelId != 0)
 	{
 		/* Process any MCS message channel PDUs. */
 		pos = Stream_GetPosition(s);
 
 		if (rdp_read_header(rdp, s, &length, &channelId))
 		{
-			if (channelId == rdp->mcs->messageChannelId)
+			if (channelId == messageChannelId)
 			{
 				UINT16 securityFlags = 0;
 
@@ -1110,19 +1116,21 @@ BOOL rdp_client_connect_auto_detect(rdpRdp* rdp, wStream* s)
 				if (securityFlags & SEC_ENCRYPT)
 				{
 					if (!rdp_decrypt(rdp, s, &length, securityFlags))
-					{
-						WLog_ERR(TAG, "rdp_decrypt failed");
 						return FALSE;
-					}
 				}
 
 				if (rdp_recv_message_channel_pdu(rdp, s, securityFlags) == STATE_RUN_SUCCESS)
 					return tpkt_ensure_stream_consumed(s, length);
 			}
 		}
+		else
+			WLog_WARN(TAG, "expected messageChannelId=" PRIu16 ", got %" PRIu16, messageChannelId,
+			          channelId);
 
 		Stream_SetPosition(s, pos);
 	}
+	else
+		WLog_WARN(TAG, "messageChannelId == 0");
 
 	return FALSE;
 }
@@ -1447,7 +1455,7 @@ BOOL rdp_server_accept_mcs_connect_initial(rdpRdp* rdp, wStream* s)
 		ADDIN_ARGV* arg;
 		rdpMcsChannel* cur = &mcs->channels[i];
 		const char* params[1] = { cur->Name };
-		WLog_INFO(TAG, " %s", cur->Name);
+		WLog_INFO(TAG, " %s [%" PRIu16 "]", cur->Name, cur->ChannelId);
 		arg = freerdp_addin_argv_new(ARRAYSIZE(params), params);
 		if (!arg)
 			return FALSE;
@@ -1495,6 +1503,7 @@ static BOOL rdp_server_skip_mcs_channel_join(rdpRdp* rdp)
 	for (UINT32 i = 0; i < mcs->channelCount; i++)
 	{
 		rdpMcsChannel* cur = &mcs->channels[i];
+		WLog_DBG(TAG, " %s [%" PRIu16 "]", cur->Name, cur->ChannelId);
 		cur->joined = TRUE;
 	}
 	return rdp_server_transition_to_state(rdp, CONNECTION_STATE_RDP_SECURITY_COMMENCEMENT);
@@ -1550,6 +1559,7 @@ BOOL rdp_server_accept_mcs_channel_join_request(rdpRdp* rdp, wStream* s)
 	for (i = 0; i < mcs->channelCount; i++)
 	{
 		rdpMcsChannel* cur = &mcs->channels[i];
+		WLog_DBG(TAG, " %s [%" PRIu16 "]", cur->Name, cur->ChannelId);
 		if (cur->ChannelId == channelId)
 			cur->joined = TRUE;
 

libfreerdp/core/info.c

@@ -969,10 +969,7 @@ BOOL rdp_recv_client_info(rdpRdp* rdp, wStream* s)
 		if (securityFlags & SEC_ENCRYPT)
 		{
 			if (!rdp_decrypt(rdp, s, &length, securityFlags))
-			{
-				WLog_ERR(TAG, "rdp_decrypt failed");
 				return FALSE;
-			}
 		}
 	}
 

libfreerdp/core/rdp.c

@@ -477,6 +477,7 @@ BOOL rdp_read_header(rdpRdp* rdp, wStream* s, UINT16* length, UINT16* channelId)
 	{
 		if (code == X224_TPDU_DISCONNECT_REQUEST)
 		{
+			WLog_WARN(TAG, "Received X224_TPDU_DISCONNECT_REQUEST, terminating");
 			utils_abort_connect(rdp);
 			return TRUE;
 		}
@@ -1306,6 +1307,7 @@ BOOL rdp_read_flow_control_pdu(wStream* s, UINT16* type, UINT16* channel_id)
 
 BOOL rdp_decrypt(rdpRdp* rdp, wStream* s, UINT16* pLength, UINT16 securityFlags)
 {
+	BOOL res = FALSE;
 	BYTE cmac[8] = { 0 };
 	BYTE wmac[8] = { 0 };
 	BOOL status = FALSE;
@@ -1328,7 +1330,7 @@ BOOL rdp_decrypt(rdpRdp* rdp, wStream* s, UINT16* pLength, UINT16 securityFlags)
 		INT64 padLength;
 
 		if (!Stream_CheckAndLogRequiredLength(TAG, s, 12))
-			return FALSE;
+			goto unlock;
 
 		Stream_Read_UINT16(s, len);    /* 0x10 */
 		Stream_Read_UINT8(s, version); /* 0x1 */
@@ -1341,64 +1343,61 @@ BOOL rdp_decrypt(rdpRdp* rdp, wStream* s, UINT16* pLength, UINT16 securityFlags)
 		if ((length <= 0) || (padLength <= 0) || (padLength > UINT16_MAX))
 		{
 			WLog_ERR(TAG, "FATAL: invalid pad length %" PRId32, padLength);
-			return FALSE;
+			goto unlock;
 		}
 
 		if (!security_fips_decrypt(Stream_Pointer(s), length, rdp))
-		{
+			goto unlock;
-			WLog_ERR(TAG, "FATAL: cannot decrypt");
-			return FALSE; /* TODO */
-		}
 
 		if (!security_fips_check_signature(Stream_Pointer(s), length - pad, sig, rdp))
-		{
+			goto unlock;
-			WLog_ERR(TAG, "FATAL: invalid packet signature");
-			return FALSE; /* TODO */
-		}
 
 		Stream_SetLength(s, Stream_Length(s) - pad);
 		*pLength = (UINT16)padLength;
-		return TRUE;
 	}
-
-	if (!Stream_CheckAndLogRequiredLength(TAG, s, sizeof(wmac)))
-		return FALSE;
-
-	Stream_Read(s, wmac, sizeof(wmac));
-	length -= sizeof(wmac);
-
-	if (length <= 0)
-	{
-		WLog_ERR(TAG, "FATAL: invalid length field");
-		return FALSE;
-	}
-
-	if (!security_decrypt(Stream_Pointer(s), length, rdp))
-		return FALSE;
-
-	if (securityFlags & SEC_SECURE_CHECKSUM)
-		status = security_salted_mac_signature(rdp, Stream_Pointer(s), length, FALSE, cmac);
 	else
-		status = security_mac_signature(rdp, Stream_Pointer(s), length, cmac);
-
-	if (!status)
-		return FALSE;
-
-	if (memcmp(wmac, cmac, sizeof(wmac)) != 0)
 	{
-		WLog_ERR(TAG, "WARNING: invalid packet signature");
+		if (!Stream_CheckAndLogRequiredLength(TAG, s, sizeof(wmac)))
-		/*
+			goto unlock;
-		 * Because Standard RDP Security is totally broken,
-		 * and cannot protect against MITM, don't treat signature
-		 * verification failure as critical. This at least enables
-		 * us to work with broken RDP clients and servers that
-		 * generate invalid signatures.
-		 */
-		// return FALSE;
-	}
 
-	*pLength = length;
+		Stream_Read(s, wmac, sizeof(wmac));
-	return TRUE;
+		length -= sizeof(wmac);
+
+		if (length <= 0)
+		{
+			WLog_ERR(TAG, "FATAL: invalid length field");
+			goto unlock;
+		}
+
+		if (!security_decrypt(Stream_Pointer(s), length, rdp))
+			goto unlock;
+
+		if (securityFlags & SEC_SECURE_CHECKSUM)
+			status = security_salted_mac_signature(rdp, Stream_Pointer(s), length, FALSE, cmac);
+		else
+			status = security_mac_signature(rdp, Stream_Pointer(s), length, cmac);
+
+		if (!status)
+			goto unlock;
+
+		if (memcmp(wmac, cmac, sizeof(wmac)) != 0)
+		{
+			WLog_ERR(TAG, "WARNING: invalid packet signature");
+			/*
+			 * Because Standard RDP Security is totally broken,
+			 * and cannot protect against MITM, don't treat signature
+			 * verification failure as critical. This at least enables
+			 * us to work with broken RDP clients and servers that
+			 * generate invalid signatures.
+			 */
+			// return FALSE;
+		}
+
+		*pLength = length;
+	}
+	res = TRUE;
+unlock:
+	return res;
 }
 
 const char* pdu_type_to_str(UINT16 pduType, char* buffer, size_t length)
@@ -1489,10 +1488,7 @@ static state_run_t rdp_recv_tpkt_pdu(rdpRdp* rdp, wStream* s)
 		if (securityFlags & (SEC_ENCRYPT | SEC_REDIRECTION_PKT))
 		{
 			if (!rdp_decrypt(rdp, s, &length, securityFlags))
-			{
-				WLog_ERR(TAG, "rdp_decrypt failed");
 				return STATE_RUN_FAILED;
-			}
 		}
 
 		if (securityFlags & SEC_REDIRECTION_PKT)

libfreerdp/core/security.c

@@ -866,9 +866,9 @@ BOOL security_fips_decrypt(BYTE* data, size_t length, rdpRdp* rdp)
 
 BOOL security_fips_check_signature(const BYTE* data, size_t length, const BYTE* sig, rdpRdp* rdp)
 {
-	BYTE buf[WINPR_SHA1_DIGEST_LENGTH];
+	BYTE buf[WINPR_SHA1_DIGEST_LENGTH] = { 0 };
-	BYTE use_count_le[4];
+	BYTE use_count_le[4] = { 0 };
-	WINPR_HMAC_CTX* hmac;
+	WINPR_HMAC_CTX* hmac = NULL;
 	BOOL result = FALSE;
 	EnterCriticalSection(&rdp->critical);
 	security_UINT32_le(use_count_le, rdp->decrypt_use_count++);
@@ -893,6 +893,8 @@ BOOL security_fips_check_signature(const BYTE* data, size_t length, const BYTE*
 		result = TRUE;
 
 out:
+	if (!result)
+		WLog_WARN(TAG, "signature check failed");
 	winpr_HMAC_Free(hmac);
 	return result;
 }