mirrors/FreeRDP
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

[core,gateway] rpc dynamic logger

Browse Source
This commit is contained in:
Armin Novak 2023-10-25 14:58:07 +02:00 committed by akallabeth
parent 36647567ac
commit 8990ffefca
4 changed files with 66 additions and 48 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

102
libfreerdp/core/gateway/rpc.c
View File

@ -205,56 +205,57 @@ static const char* vc_state_str(VIRTUAL_CONNECTION_STATE state)
*
*/
void rpc_pdu_header_print(const rpcconn_hdr_t* header)
void rpc_pdu_header_print(wLog* log, const rpcconn_hdr_t* header)
{
WINPR_ASSERT(header);
WLog_INFO(TAG, "rpc_vers: %" PRIu8 "", header->common.rpc_vers);
WLog_INFO(TAG, "rpc_vers_minor: %" PRIu8 "", header->common.rpc_vers_minor);
WLog_Print(log, WLOG_INFO, "rpc_vers: %" PRIu8 "", header->common.rpc_vers);
WLog_Print(log, WLOG_INFO, "rpc_vers_minor: %" PRIu8 "", header->common.rpc_vers_minor);
if (header->common.ptype > PTYPE_RTS)
WLog_INFO(TAG, "ptype: %s (%" PRIu8 ")", "PTYPE_UNKNOWN", header->common.ptype);
WLog_Print(log, WLOG_INFO, "ptype: %s (%" PRIu8 ")", "PTYPE_UNKNOWN", header->common.ptype);
else
WLog_INFO(TAG, "ptype: %s (%" PRIu8 ")", PTYPE_STRINGS[header->common.ptype],
header->common.ptype);
WLog_Print(log, WLOG_INFO, "ptype: %s (%" PRIu8 ")", PTYPE_STRINGS[header->common.ptype],
header->common.ptype);
WLog_INFO(TAG, "pfc_flags (0x%02" PRIX8 ") = {", header->common.pfc_flags);
WLog_Print(log, WLOG_INFO, "pfc_flags (0x%02" PRIX8 ") = {", header->common.pfc_flags);
if (header->common.pfc_flags & PFC_FIRST_FRAG)
WLog_INFO(TAG, " PFC_FIRST_FRAG");
WLog_Print(log, WLOG_INFO, " PFC_FIRST_FRAG");
if (header->common.pfc_flags & PFC_LAST_FRAG)
WLog_INFO(TAG, " PFC_LAST_FRAG");
WLog_Print(log, WLOG_INFO, " PFC_LAST_FRAG");
if (header->common.pfc_flags & PFC_PENDING_CANCEL)
WLog_INFO(TAG, " PFC_PENDING_CANCEL");
WLog_Print(log, WLOG_INFO, " PFC_PENDING_CANCEL");
if (header->common.pfc_flags & PFC_RESERVED_1)
WLog_INFO(TAG, " PFC_RESERVED_1");
WLog_Print(log, WLOG_INFO, " PFC_RESERVED_1");
if (header->common.pfc_flags & PFC_CONC_MPX)
WLog_INFO(TAG, " PFC_CONC_MPX");
WLog_Print(log, WLOG_INFO, " PFC_CONC_MPX");
if (header->common.pfc_flags & PFC_DID_NOT_EXECUTE)
WLog_INFO(TAG, " PFC_DID_NOT_EXECUTE");
WLog_Print(log, WLOG_INFO, " PFC_DID_NOT_EXECUTE");
if (header->common.pfc_flags & PFC_OBJECT_UUID)
WLog_INFO(TAG, " PFC_OBJECT_UUID");
WLog_Print(log, WLOG_INFO, " PFC_OBJECT_UUID");
WLog_INFO(TAG, " }");
WLog_INFO(TAG, "packed_drep[4]: %02" PRIX8 " %02" PRIX8 " %02" PRIX8 " %02" PRIX8 "",
header->common.packed_drep[0], header->common.packed_drep[1],
header->common.packed_drep[2], header->common.packed_drep[3]);
WLog_INFO(TAG, "frag_length: %" PRIu16 "", header->common.frag_length);
WLog_INFO(TAG, "auth_length: %" PRIu16 "", header->common.auth_length);
WLog_INFO(TAG, "call_id: %" PRIu32 "", header->common.call_id);
WLog_Print(log, WLOG_INFO, " }");
WLog_Print(log, WLOG_INFO,
"packed_drep[4]: %02" PRIX8 " %02" PRIX8 " %02" PRIX8 " %02" PRIX8 "",
header->common.packed_drep[0], header->common.packed_drep[1],
header->common.packed_drep[2], header->common.packed_drep[3]);
WLog_Print(log, WLOG_INFO, "frag_length: %" PRIu16 "", header->common.frag_length);
WLog_Print(log, WLOG_INFO, "auth_length: %" PRIu16 "", header->common.auth_length);
WLog_Print(log, WLOG_INFO, "call_id: %" PRIu32 "", header->common.call_id);
if (header->common.ptype == PTYPE_RESPONSE)
{
WLog_INFO(TAG, "alloc_hint: %" PRIu32 "", header->response.alloc_hint);
WLog_INFO(TAG, "p_cont_id: %" PRIu16 "", header->response.p_cont_id);
WLog_INFO(TAG, "cancel_count: %" PRIu8 "", header->response.cancel_count);
WLog_INFO(TAG, "reserved: %" PRIu8 "", header->response.reserved);
WLog_Print(log, WLOG_INFO, "alloc_hint: %" PRIu32 "", header->response.alloc_hint);
WLog_Print(log, WLOG_INFO, "p_cont_id: %" PRIu16 "", header->response.p_cont_id);
WLog_Print(log, WLOG_INFO, "cancel_count: %" PRIu8 "", header->response.cancel_count);
WLog_Print(log, WLOG_INFO, "reserved: %" PRIu8 "", header->response.reserved);
}
}
@ -362,7 +363,8 @@ size_t rpc_offset_pad(size_t* offset, size_t pad)
*
*/
BOOL rpc_get_stub_data_info(const rpcconn_hdr_t* header, size_t* poffset, size_t* length)
BOOL rpc_get_stub_data_info(rdpRpc* rpc, const rpcconn_hdr_t* header, size_t* poffset,
size_t* length)
{
size_t used = 0;
size_t offset = 0;
@ -373,6 +375,7 @@ BOOL rpc_get_stub_data_info(const rpcconn_hdr_t* header, size_t* poffset, size_t
UINT32 sec_trailer_offset;
const rpc_sec_trailer* sec_trailer = NULL;
WINPR_ASSERT(rpc);
WINPR_ASSERT(header);
WINPR_ASSERT(poffset);
WINPR_ASSERT(length);
@ -398,7 +401,7 @@ BOOL rpc_get_stub_data_info(const rpcconn_hdr_t* header, size_t* poffset, size_t
break;
default:
WLog_ERR(TAG, "Unknown PTYPE: 0x%02" PRIX8 "", header->common.ptype);
WLog_Print(rpc->log, WLOG_ERROR, "Unknown PTYPE: 0x%02" PRIX8 "", header->common.ptype);
goto fail;
}
@ -432,8 +435,9 @@ BOOL rpc_get_stub_data_info(const rpcconn_hdr_t* header, size_t* poffset, size_t
if ((frag_length - (sec_trailer_offset + 8)) != auth_length)
{
WLog_ERR(TAG, "invalid auth_length: actual: %" PRIu32 ", expected: %" PRIu32 "",
auth_length, (frag_length - (sec_trailer_offset + 8)));
WLog_Print(rpc->log, WLOG_ERROR,
"invalid auth_length: actual: %" PRIu32 ", expected: %" PRIu32 "", auth_length,
(frag_length - (sec_trailer_offset + 8)));
}
*length = sec_trailer_offset - auth_pad_length - offset;
@ -462,7 +466,7 @@ SSIZE_T rpc_channel_read(RpcChannel* channel, wStream* s, size_t length)
if (BIO_should_retry(channel->tls->bio))
return 0;
WLog_ERR(TAG, "rpc_channel_read: Out of retries");
WLog_Print(channel->rpc->log, WLOG_ERROR, "rpc_channel_read: Out of retries");
return -1;
}
@ -479,12 +483,11 @@ SSIZE_T rpc_channel_write(RpcChannel* channel, const BYTE* data, size_t length)
BOOL rpc_in_channel_transition_to_state(RpcInChannel* inChannel, CLIENT_IN_CHANNEL_STATE state)
{
if (!inChannel)
return FALSE;
inChannel->State = state;
WLog_DBG(TAG, "%s", client_in_state_str(state));
WLog_Print(inChannel->common.rpc->log, WLOG_DEBUG, "%s", client_in_state_str(state));
return TRUE;
}
@ -527,6 +530,10 @@ static int rpc_channel_rpch_init(RpcClient* client, RpcChannel* channel, const c
static int rpc_in_channel_init(rdpRpc* rpc, RpcInChannel* inChannel)
{
WINPR_ASSERT(rpc);
WINPR_ASSERT(inChannel);
inChannel->common.rpc = rpc;
inChannel->State = CLIENT_IN_CHANNEL_STATE_INITIAL;
inChannel->BytesSent = 0;
inChannel->SenderAvailableWindow = rpc->ReceiveWindow;
@ -541,8 +548,7 @@ static int rpc_in_channel_init(rdpRpc* rpc, RpcInChannel* inChannel)
static RpcInChannel* rpc_in_channel_new(rdpRpc* rpc)
{
RpcInChannel* inChannel = NULL;
inChannel = (RpcInChannel*)calloc(1, sizeof(RpcInChannel));
RpcInChannel* inChannel = (RpcInChannel*)calloc(1, sizeof(RpcInChannel));
if (inChannel)
{
@ -569,12 +575,16 @@ BOOL rpc_out_channel_transition_to_state(RpcOutChannel* outChannel, CLIENT_OUT_C
return FALSE;
outChannel->State = state;
WLog_DBG(TAG, "%s", client_out_state_str(state));
WLog_Print(outChannel->common.rpc->log, WLOG_DEBUG, "%s", client_out_state_str(state));
return TRUE;
}
static int rpc_out_channel_init(rdpRpc* rpc, RpcOutChannel* outChannel)
{
WINPR_ASSERT(rpc);
WINPR_ASSERT(outChannel);
outChannel->common.rpc = rpc;
outChannel->State = CLIENT_OUT_CHANNEL_STATE_INITIAL;
outChannel->BytesReceived = 0;
outChannel->ReceiverAvailableWindow = rpc->ReceiveWindow;
@ -590,8 +600,7 @@ static int rpc_out_channel_init(rdpRpc* rpc, RpcOutChannel* outChannel)
RpcOutChannel* rpc_out_channel_new(rdpRpc* rpc)
{
RpcOutChannel* outChannel = NULL;
outChannel = (RpcOutChannel*)calloc(1, sizeof(RpcOutChannel));
RpcOutChannel* outChannel = (RpcOutChannel*)calloc(1, sizeof(RpcOutChannel));
if (outChannel)
{
@ -607,15 +616,18 @@ BOOL rpc_virtual_connection_transition_to_state(rdpRpc* rpc, RpcVirtualConnectio
if (!connection)
return FALSE;
WINPR_ASSERT(rpc);
connection->State = state;
WLog_DBG(TAG, "%s", vc_state_str(state));
WLog_Print(rpc->log, WLOG_DEBUG, "%s", vc_state_str(state));
return TRUE;
}
static RpcVirtualConnection* rpc_virtual_connection_new(rdpRpc* rpc)
{
RpcVirtualConnection* connection;
connection = (RpcVirtualConnection*)calloc(1, sizeof(RpcVirtualConnection));
WINPR_ASSERT(rpc);
RpcVirtualConnection* connection =
(RpcVirtualConnection*)calloc(1, sizeof(RpcVirtualConnection));
if (!connection)
return NULL;
@ -766,7 +778,8 @@ static int rpc_in_channel_connect(RpcInChannel* inChannel, UINT32 timeout)
if (!rpc_ncacn_http_send_in_channel_request(&inChannel->common))
{
WLog_ERR(TAG, "rpc_ncacn_http_send_in_channel_request failure");
WLog_Print(inChannel->common.rpc->log, WLOG_ERROR,
"rpc_ncacn_http_send_in_channel_request failure");
return -1;
}
@ -799,7 +812,8 @@ static int rpc_out_channel_connect(RpcOutChannel* outChannel, int timeout)
if (!rpc_ncacn_http_send_out_channel_request(&outChannel->common, FALSE))
{
WLog_ERR(TAG, "rpc_ncacn_http_send_out_channel_request failure");
WLog_Print(outChannel->common.rpc->log, WLOG_ERROR,
"rpc_ncacn_http_send_out_channel_request failure");
return FALSE;
}
@ -830,7 +844,8 @@ int rpc_out_channel_replacement_connect(RpcOutChannel* outChannel, int timeout)
if (!rpc_ncacn_http_send_out_channel_request(&outChannel->common, TRUE))
{
WLog_ERR(TAG, "rpc_ncacn_http_send_out_channel_request failure");
WLog_Print(outChannel->common.rpc->log, WLOG_ERROR,
"rpc_ncacn_http_send_out_channel_request failure");
return FALSE;
}
@ -874,6 +889,7 @@ rdpRpc* rpc_new(rdpTransport* transport)
if (!rpc)
return NULL;
rpc->log = WLog_Get(TAG);
rpc->State = RPC_CLIENT_STATE_INITIAL;
rpc->transport = transport;
rpc->SendSeqNum = 0;

6
libfreerdp/core/gateway/rpc.h
View File

@ -603,6 +603,7 @@ typedef struct
rdpCredsspAuth* auth;
HttpContext* http;
BYTE Cookie[16];
rdpRpc* rpc;
} RpcChannel;
/* Ping Originator */
@ -749,15 +750,16 @@ struct rdp_rpc
UINT32 CurrentKeepAliveInterval;
RpcVirtualConnection* VirtualConnection;
wLog* log;
};
FREERDP_LOCAL void rpc_pdu_header_print(const rpcconn_hdr_t* header);
FREERDP_LOCAL void rpc_pdu_header_print(wLog* log, const rpcconn_hdr_t* header);
FREERDP_LOCAL rpcconn_common_hdr_t rpc_pdu_header_init(const rdpRpc* rpc);
FREERDP_LOCAL size_t rpc_offset_align(size_t* offset, size_t alignment);
FREERDP_LOCAL size_t rpc_offset_pad(size_t* offset, size_t pad);
FREERDP_LOCAL BOOL rpc_get_stub_data_info(const rpcconn_hdr_t* header, size_t* offset,
FREERDP_LOCAL BOOL rpc_get_stub_data_info(rdpRpc* rpc, const rpcconn_hdr_t* header, size_t* offset,
size_t* length);
FREERDP_LOCAL SSIZE_T rpc_channel_write(RpcChannel* channel, const BYTE* data, size_t length);

2
libfreerdp/core/gateway/rpc_client.c
View File

@ -406,7 +406,7 @@ static int rpc_client_recv_fragment(rdpRpc* rpc, wStream* fragment)
goto fail;
}
if (!rpc_get_stub_data_info(&header, &StubOffset, &StubLength))
if (!rpc_get_stub_data_info(rpc, &header, &StubOffset, &StubLength))
{
WLog_ERR(TAG, "expected stub");
goto fail;

4
libfreerdp/core/gateway/rts.c
View File

@ -1817,7 +1817,7 @@ static int rts_recv_flow_control_ack_with_destination_pdu(rdpRpc* rpc, wStream*
{
char buffer1[64] = { 0 };
char buffer2[64] = { 0 };
WLog_Print(log, WLOG_ERROR, "got command %s, expected %s",
WLog_Print(rpc->log, WLOG_ERROR, "got command %s, expected %s",
rts_command_to_string(Command, buffer1, sizeof(buffer1)),
rts_command_to_string(RTS_CMD_DESTINATION, buffer2, sizeof(buffer2)));
return -1;
@ -1838,7 +1838,7 @@ static int rts_recv_flow_control_ack_with_destination_pdu(rdpRpc* rpc, wStream*
case FDOutProxy:
break;
default:
WLog_Print(log, WLOG_ERROR,
WLog_Print(rpc->log, WLOG_ERROR,
"got destination %" PRIu32
", expected one of [FDClient[0]|FDInProxy[1]|FDServer[2]|FDOutProxy[3]",
Destination);