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

[server,proxy] improve rdpdr channel logging

Browse Source
This commit is contained in:
Armin Novak 2022-12-22 12:14:30 +01:00 committed by David Fort
parent 37454c7420
commit b614a2da37
3 changed files with 249 additions and 171 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

306
server/proxy/channels/pf_channel_rdpdr.c
View File

@ -71,6 +71,7 @@ typedef struct
UINT16 maxMajorVersion;
UINT16 maxMinorVersion;
wQueue* queue;
wLog* log;
} pf_channel_client_context;
typedef enum
@ -89,8 +90,69 @@ typedef struct
DWORD SessionId;
HANDLE handle;
wArrayList* blockedDevices;
wLog* log;
} pf_channel_server_context;
#define proxy_client "[proxy<-->client]"
#define proxy_server "[proxy<-->server]"
#define proxy_client_rx proxy_client " receive"
#define proxy_client_tx proxy_client " send"
#define proxy_server_rx proxy_server " receive"
#define proxy_server_tx proxy_server " send"
#define SERVER_RX_LOG(log, lvl, fmt, ...) WLog_Print(log, lvl, proxy_client_rx fmt, ##__VA_ARGS__)
#define CLIENT_RX_LOG(log, lvl, fmt, ...) WLog_Print(log, lvl, proxy_server_rx fmt, ##__VA_ARGS__)
#define SERVER_TX_LOG(log, lvl, fmt, ...) WLog_Print(log, lvl, proxy_client_tx fmt, ##__VA_ARGS__)
#define CLIENT_TX_LOG(log, lvl, fmt, ...) WLog_Print(log, lvl, proxy_server_tx fmt, ##__VA_ARGS__)
#define RX_LOG(srv, lvl, fmt, ...) \
do \
{ \
if (srv) \
{ \
SERVER_RX_LOG(lvl, fmt, ##__VA_ARGS__); \
} \
else \
{ \
CLIENT_RX_LOG(lvl, fmt, ##__VA_ARGS__); \
} \
} while (0)
#define SERVER_RXTX_LOG(send, log, lvl, fmt, ...) \
do \
{ \
if (send) \
{ \
SERVER_TX_LOG(log, lvl, fmt, ##__VA_ARGS__); \
} \
else \
{ \
SERVER_RX_LOG(log, lvl, fmt, ##__VA_ARGS__); \
} \
} while (0)
#define Stream_CheckAndLogRequiredLengthSrv(log, s, len) \
Stream_CheckAndLogRequiredLengthWLogEx(log, WLOG_WARN, s, len, \
proxy_client_rx " %s(%s:%" PRIuz ")", __FUNCTION__, \
__FILE__, __LINE__)
#define Stream_CheckAndLogRequiredLengthClient(log, s, len) \
Stream_CheckAndLogRequiredLengthWLogEx(log, WLOG_WARN, s, len, \
proxy_server_rx " %s(%s:%" PRIuz ")", __FUNCTION__, \
__FILE__, __LINE__)
#define Stream_CheckAndLogRequiredLengthRx(srv, log, s, len) \
({ \
BOOL res; \
if (srv) \
{ \
res = Stream_CheckAndLogRequiredLengthSrv(log, s, len); \
} \
else \
{ \
res = Stream_CheckAndLogRequiredLengthClient(log, s, len); \
} \
res; \
})
static const char* rdpdr_server_state_to_string(pf_channel_server_state state)
{
switch (state)
@ -155,17 +217,19 @@ static wStream* rdpdr_server_get_send_buffer(pf_channel_server_context* rdpdr, U
return rdpdr_get_send_buffer(&rdpdr->common, component, PacketID, capacity);
}
static UINT rdpdr_client_send(pClientContext* pc, wStream* s)
static UINT rdpdr_client_send(wLog* log, pClientContext* pc, wStream* s)
{
UINT16 channelId;
WINPR_ASSERT(log);
WINPR_ASSERT(pc);
WINPR_ASSERT(s);
WINPR_ASSERT(pc->context.instance);
if (!pc->connected)
{
WLog_WARN(TAG, "Ignoring channel %s message, not connected!", RDPDR_SVC_CHANNEL_NAME);
CLIENT_TX_LOG(log, WLOG_WARN, "Ignoring channel %s message, not connected!",
RDPDR_SVC_CHANNEL_NAME);
return CHANNEL_RC_OK;
}
@ -176,7 +240,7 @@ static UINT rdpdr_client_send(pClientContext* pc, wStream* s)
return ERROR_INTERNAL_ERROR;
Stream_SealLength(s);
rdpdr_dump_send_packet(WLog_Get(TAG), WLOG_TRACE, s, "proxy-client");
rdpdr_dump_send_packet(log, WLOG_TRACE, s, proxy_server_tx);
WINPR_ASSERT(pc->context.instance->SendChannelData);
if (!pc->context.instance->SendChannelData(pc->context.instance, channelId, Stream_Buffer(s),
Stream_Length(s)))
@ -197,19 +261,20 @@ static UINT rdpdr_seal_send_free_request(pf_channel_server_context* context, wSt
len = Stream_Length(s);
WINPR_ASSERT(len <= ULONG_MAX);
rdpdr_dump_send_packet(context->log, WLOG_TRACE, s, proxy_client_tx);
status = WTSVirtualChannelWrite(context->handle, (char*)Stream_Buffer(s), (ULONG)len, NULL);
return (status) ? CHANNEL_RC_OK : ERROR_INTERNAL_ERROR;
}
static BOOL rdpdr_process_server_header(wStream* s, UINT16 component, UINT16 PacketId,
size_t expect)
static BOOL rdpdr_process_server_header(BOOL server, wLog* log, wStream* s, UINT16 component,
UINT16 PacketId, size_t expect)
{
UINT16 rpacketid, rcomponent;
WINPR_ASSERT(s);
if (!Stream_CheckAndLogRequiredLength(TAG, s, 4))
if (!Stream_CheckAndLogRequiredLengthRx(server, log, s, 4))
{
WLog_WARN(TAG, "RDPDR_HEADER[%s | %s]: expected length 4, got %" PRIuz,
RX_LOG(server, log, WLOG_WARN, "RDPDR_HEADER[%s | %s]: expected length 4, got %" PRIuz,
rdpdr_component_string(component), rdpdr_packetid_string(PacketId),
Stream_GetRemainingLength(s));
return FALSE;
@ -220,21 +285,23 @@ static BOOL rdpdr_process_server_header(wStream* s, UINT16 component, UINT16 Pac
if (rcomponent != component)
{
WLog_WARN(TAG, "RDPDR_HEADER[%s | %s]: got component %s", rdpdr_component_string(component),
rdpdr_packetid_string(PacketId), rdpdr_component_string(rcomponent));
RX_LOG(server, log, WLOG_WARN, "RDPDR_HEADER[%s | %s]: got component %s",
rdpdr_component_string(component), rdpdr_packetid_string(PacketId),
rdpdr_component_string(rcomponent));
return FALSE;
}
if (rpacketid != PacketId)
{
WLog_WARN(TAG, "RDPDR_HEADER[%s | %s]: got PacketID %s", rdpdr_component_string(component),
rdpdr_packetid_string(PacketId), rdpdr_packetid_string(rpacketid));
RX_LOG(server, log, WLOG_WARN, "RDPDR_HEADER[%s | %s]: got PacketID %s",
rdpdr_component_string(component), rdpdr_packetid_string(PacketId),
rdpdr_packetid_string(rpacketid));
return FALSE;
}
if (!Stream_CheckAndLogRequiredLength(TAG, s, expect))
if (!Stream_CheckAndLogRequiredLengthRx(server, log, s, expect))
{
WLog_WARN(TAG,
RX_LOG(server, log, WLOG_WARN,
"RDPDR_HEADER[%s | %s] not enought data, expected %" PRIuz ", "
"got %" PRIuz,
rdpdr_component_string(component), rdpdr_packetid_string(PacketId), expect,
@ -242,18 +309,15 @@ static BOOL rdpdr_process_server_header(wStream* s, UINT16 component, UINT16 Pac
return ERROR_INVALID_DATA;
}
WLog_DBG(TAG, "RDPDR_HEADER[%s | %s] -> got %" PRIuz " bytes",
rdpdr_component_string(component), rdpdr_packetid_string(PacketId),
Stream_GetRemainingLength(s));
return TRUE;
}
static BOOL rdpdr_check_version(UINT16 versionMajor, UINT16 versionMinor, UINT16 component,
UINT16 PacketId)
static BOOL rdpdr_check_version(BOOL server, wLog* log, UINT16 versionMajor, UINT16 versionMinor,
UINT16 component, UINT16 PacketId)
{
if (versionMajor != RDPDR_VERSION_MAJOR)
{
WLog_WARN(TAG, "[%s | %s] expected MajorVersion %" PRIu16 ", got %" PRIu16,
RX_LOG(server, log, WLOG_WARN, "[%s | %s] expected MajorVersion %" PRIu16 ", got %" PRIu16,
rdpdr_component_string(component), rdpdr_packetid_string(PacketId),
RDPDR_VERSION_MAJOR, versionMajor);
return FALSE;
@ -268,7 +332,7 @@ static BOOL rdpdr_check_version(UINT16 versionMajor, UINT16 versionMinor, UINT16
break;
default:
{
WLog_WARN(TAG, "[%s | %s] unsupported MinorVersion %" PRIu16,
RX_LOG(server, log, WLOG_WARN, "[%s | %s] unsupported MinorVersion %" PRIu16,
rdpdr_component_string(component), rdpdr_packetid_string(PacketId),
versionMinor);
return FALSE;
@ -284,14 +348,14 @@ static UINT rdpdr_process_server_announce_request(pf_channel_client_context* rdp
WINPR_ASSERT(rdpdr);
WINPR_ASSERT(s);
if (!rdpdr_process_server_header(s, component, packetid, 8))
if (!rdpdr_process_server_header(FALSE, rdpdr->log, s, component, packetid, 8))
return ERROR_INVALID_DATA;
Stream_Read_UINT16(s, rdpdr->common.versionMajor);
Stream_Read_UINT16(s, rdpdr->common.versionMinor);
if (!rdpdr_check_version(rdpdr->common.versionMajor, rdpdr->common.versionMinor, component,
packetid))
if (!rdpdr_check_version(FALSE, rdpdr->log, rdpdr->common.versionMajor,
rdpdr->common.versionMinor, component, packetid))
return ERROR_INVALID_DATA;
/* Limit maximum channel protocol version to the one set by proxy server */
@ -304,7 +368,6 @@ static UINT rdpdr_process_server_announce_request(pf_channel_client_context* rdp
rdpdr->common.versionMinor = rdpdr->maxMinorVersion;
Stream_Read_UINT32(s, rdpdr->common.clientID);
WLog_DBG(TAG, "[receive] server->client clientID=0x%08" PRIx32, rdpdr->common.clientID);
return CHANNEL_RC_OK;
}
@ -318,7 +381,6 @@ static UINT rdpdr_server_send_announce_request(pf_channel_server_context* contex
Stream_Write_UINT16(s, context->common.versionMajor); /* VersionMajor (2 bytes) */
Stream_Write_UINT16(s, context->common.versionMinor); /* VersionMinor (2 bytes) */
Stream_Write_UINT32(s, context->common.clientID); /* ClientId (4 bytes) */
WLog_DBG(TAG, "[send] server->client clientID=0x%08" PRIx32, context->common.clientID);
return rdpdr_seal_send_free_request(context, s);
}
@ -332,20 +394,20 @@ static UINT rdpdr_process_client_announce_reply(pf_channel_server_context* rdpdr
WINPR_ASSERT(rdpdr);
WINPR_ASSERT(s);
if (!rdpdr_process_server_header(s, component, packetid, 8))
if (!rdpdr_process_server_header(TRUE, rdpdr->log, s, component, packetid, 8))
return ERROR_INVALID_DATA;
Stream_Read_UINT16(s, versionMajor);
Stream_Read_UINT16(s, versionMinor);
if (!rdpdr_check_version(versionMajor, versionMinor, component, packetid))
if (!rdpdr_check_version(TRUE, rdpdr->log, versionMajor, versionMinor, component, packetid))
return ERROR_INVALID_DATA;
if ((rdpdr->common.versionMajor != versionMajor) ||
(rdpdr->common.versionMinor != versionMinor))
{
WLog_WARN(
TAG,
SERVER_RX_LOG(
rdpdr->log, WLOG_WARN,
"[%s | %s] downgrading version from %" PRIu16 ".%" PRIu16 " to %" PRIu16 ".%" PRIu16,
rdpdr_component_string(component), rdpdr_packetid_string(packetid),
rdpdr->common.versionMajor, rdpdr->common.versionMinor, versionMajor, versionMinor);
@ -353,10 +415,10 @@ static UINT rdpdr_process_client_announce_reply(pf_channel_server_context* rdpdr
rdpdr->common.versionMinor = versionMinor;
}
Stream_Read_UINT32(s, clientID);
WLog_DBG(TAG, "[receive] client->server clientID=0x%08" PRIx32, clientID);
if (rdpdr->common.clientID != clientID)
{
WLog_WARN(TAG, "[%s | %s] changing clientID 0x%08" PRIu32 " to 0x%08" PRIu32,
SERVER_RX_LOG(rdpdr->log, WLOG_WARN,
"[%s | %s] changing clientID 0x%08" PRIu32 " to 0x%08" PRIu32,
rdpdr_component_string(component), rdpdr_packetid_string(packetid),
rdpdr->common.clientID, clientID);
rdpdr->common.clientID = clientID;
@ -375,8 +437,7 @@ static UINT rdpdr_send_client_announce_reply(pClientContext* pc, pf_channel_clie
Stream_Write_UINT16(s, rdpdr->common.versionMajor);
Stream_Write_UINT16(s, rdpdr->common.versionMinor);
Stream_Write_UINT32(s, rdpdr->common.clientID);
WLog_DBG(TAG, "[send] client->server clientID=0x%08" PRIx32, rdpdr->common.clientID);
return rdpdr_client_send(pc, s);
return rdpdr_client_send(rdpdr->log, pc, s);
}
static UINT rdpdr_process_client_name_request(pf_channel_server_context* rdpdr, wStream* s,
@ -390,7 +451,8 @@ static UINT rdpdr_process_client_name_request(pf_channel_server_context* rdpdr,
WINPR_ASSERT(s);
WINPR_ASSERT(pc);
if (!rdpdr_process_server_header(s, RDPDR_CTYP_CORE, PAKID_CORE_CLIENT_NAME, 12))
if (!rdpdr_process_server_header(TRUE, rdpdr->log, s, RDPDR_CTYP_CORE, PAKID_CORE_CLIENT_NAME,
12))
return ERROR_INVALID_DATA;
Stream_Read_UINT32(s, unicodeFlag);
@ -399,12 +461,12 @@ static UINT rdpdr_process_client_name_request(pf_channel_server_context* rdpdr,
Stream_Read_UINT32(s, codePage);
WINPR_UNUSED(codePage); /* Field is ignored */
Stream_Read_UINT32(s, rdpdr->common.computerNameLen);
if (!Stream_CheckAndLogRequiredLength(TAG, s, rdpdr->common.computerNameLen))
if (!Stream_CheckAndLogRequiredLengthSrv(rdpdr->log, s, rdpdr->common.computerNameLen))
{
WLog_WARN(TAG, "[%s | %s]: missing data, got " PRIu32 ", expected %" PRIu32,
rdpdr_component_string(RDPDR_CTYP_CORE),
rdpdr_packetid_string(PAKID_CORE_CLIENT_NAME), Stream_GetRemainingLength(s),
rdpdr->common.computerNameLen);
SERVER_RX_LOG(
rdpdr->log, WLOG_WARN, "[%s | %s]: missing data, got " PRIu32 ", expected %" PRIu32,
rdpdr_component_string(RDPDR_CTYP_CORE), rdpdr_packetid_string(PAKID_CORE_CLIENT_NAME),
Stream_GetRemainingLength(s), rdpdr->common.computerNameLen);
return ERROR_INVALID_DATA;
}
tmp = realloc(rdpdr->common.computerName.v, rdpdr->common.computerNameLen);
@ -452,21 +514,24 @@ static UINT rdpdr_send_client_name_request(pClientContext* pc, pf_channel_client
Stream_Write_UINT32(s, 0); /* codePage, must be set to zero */
Stream_Write_UINT32(s, rdpdr->common.computerNameLen);
Stream_Write(s, rdpdr->common.computerName.v, rdpdr->common.computerNameLen);
return rdpdr_client_send(pc, s);
return rdpdr_client_send(rdpdr->log, pc, s);
}
#define rdpdr_ignore_capset(s, length) rdpdr_ignore_capset_((s), length, __FUNCTION__)
static UINT rdpdr_ignore_capset_(wStream* s, size_t capabilityLength, const char* fkt)
#define rdpdr_ignore_capset(srv, log, s, length) \
rdpdr_ignore_capset_((srv), (log), (s), length, __FUNCTION__)
static UINT rdpdr_ignore_capset_(BOOL srv, wLog* log, wStream* s, size_t capabilityLength,
const char* fkt)
{
WINPR_ASSERT(s);
if (capabilityLength < 4)
{
WLog_ERR(TAG, "[%s] invalid capabilityLength %" PRIu16 " < 4", fkt, capabilityLength);
RX_LOG(srv, log, WLOG_ERROR, "[%s] invalid capabilityLength %" PRIu16 " < 4", fkt,
capabilityLength);
return ERROR_INVALID_DATA;
}
if (!Stream_CheckAndLogRequiredLengthEx(TAG, WLOG_ERROR, s, capabilityLength - 4U,
if (!Stream_CheckAndLogRequiredLengthWLogEx(log, WLOG_ERROR, s, capabilityLength - 4U,
"%s::capabilityLength", fkt))
return ERROR_INVALID_DATA;
@ -478,33 +543,33 @@ static UINT rdpdr_client_process_general_capset(pf_channel_client_context* rdpdr
size_t length)
{
WINPR_UNUSED(rdpdr);
return rdpdr_ignore_capset(s, length);
return rdpdr_ignore_capset(FALSE, rdpdr->log, s, length);
}
static UINT rdpdr_process_printer_capset(pf_channel_client_context* rdpdr, wStream* s,
size_t length)
{
WINPR_UNUSED(rdpdr);
return rdpdr_ignore_capset(s, length);
return rdpdr_ignore_capset(FALSE, rdpdr->log, s, length);
}
static UINT rdpdr_process_port_capset(pf_channel_client_context* rdpdr, wStream* s, size_t length)
{
WINPR_UNUSED(rdpdr);
return rdpdr_ignore_capset(s, length);
return rdpdr_ignore_capset(FALSE, rdpdr->log, s, length);
}
static UINT rdpdr_process_drive_capset(pf_channel_client_context* rdpdr, wStream* s, size_t length)
{
WINPR_UNUSED(rdpdr);
return rdpdr_ignore_capset(s, length);
return rdpdr_ignore_capset(FALSE, rdpdr->log, s, length);
}
static UINT rdpdr_process_smartcard_capset(pf_channel_client_context* rdpdr, wStream* s,
size_t length)
{
WINPR_UNUSED(rdpdr);
return rdpdr_ignore_capset(s, length);
return rdpdr_ignore_capset(FALSE, rdpdr->log, s, length);
}
static UINT rdpdr_process_server_core_capability_request(pf_channel_client_context* rdpdr,
@ -516,26 +581,24 @@ static UINT rdpdr_process_server_core_capability_request(pf_channel_client_conte
WINPR_ASSERT(rdpdr);
if (!rdpdr_process_server_header(s, RDPDR_CTYP_CORE, PAKID_CORE_SERVER_CAPABILITY, 4))
if (!rdpdr_process_server_header(FALSE, rdpdr->log, s, RDPDR_CTYP_CORE,
PAKID_CORE_SERVER_CAPABILITY, 4))
return ERROR_INVALID_DATA;
Stream_Read_UINT16(s, numCapabilities);
Stream_Seek(s, 2); /* pad (2 bytes) */
WLog_DBG(TAG, "[server] got %" PRIu16 " capabilities:", numCapabilities);
for (i = 0; i < numCapabilities; i++)
{
UINT16 capabilityType;
UINT16 capabilityLength;
if (!Stream_CheckAndLogRequiredLength(TAG, s, 2 * sizeof(UINT16)))
if (!Stream_CheckAndLogRequiredLengthClient(rdpdr->log, s, 2 * sizeof(UINT16)))
return ERROR_INVALID_DATA;
Stream_Read_UINT16(s, capabilityType);
Stream_Read_UINT16(s, capabilityLength);
WLog_DBG(TAG, "[server] [%" PRIu16 "] got capability %s [%" PRIu16 "]", i,
rdpdr_cap_type_string(capabilityType), capabilityLength);
switch (capabilityType)
{
case CAP_GENERAL_TYPE:
@ -672,22 +735,22 @@ static UINT rdpdr_process_client_capability_response(pf_channel_server_context*
UINT16 numCapabilities, x;
WINPR_ASSERT(rdpdr);
if (!rdpdr_process_server_header(s, component, packetid, 4))
if (!rdpdr_process_server_header(TRUE, rdpdr->log, s, component, packetid, 4))
return ERROR_INVALID_DATA;
Stream_Read_UINT16(s, numCapabilities);
Stream_Seek_UINT16(s); /* padding */
WLog_DBG(TAG, "[client] got %" PRIu16 " capabilities:", numCapabilities);
for (x = 0; x < numCapabilities; x++)
{
UINT16 capabilityType;
UINT16 capabilityLength;
if (!Stream_CheckAndLogRequiredLength(TAG, s, 2 * sizeof(UINT16)))
if (!Stream_CheckAndLogRequiredLengthSrv(rdpdr->log, s, 2 * sizeof(UINT16)))
{
WLog_WARN(TAG,
"[%s | %s] invalid capability length 0x" PRIu16 ", expected at least %" PRIuz,
SERVER_RX_LOG(rdpdr->log, WLOG_WARN,
"[%s | %s] invalid capability length 0x" PRIu16
", expected at least %" PRIuz,
rdpdr_component_string(component), rdpdr_packetid_string(packetid),
Stream_GetRemainingLength(s), sizeof(UINT16));
return ERROR_INVALID_DATA;
@ -695,33 +758,32 @@ static UINT rdpdr_process_client_capability_response(pf_channel_server_context*
Stream_Read_UINT16(s, capabilityType);
Stream_Read_UINT16(s, capabilityLength);
WLog_DBG(TAG, "[client] [%" PRIu16 "] got capability %s [%" PRIu16 "]", x,
rdpdr_cap_type_string(capabilityType), capabilityLength);
switch (capabilityType)
{
case CAP_GENERAL_TYPE:
status = rdpdr_ignore_capset(s, capabilityLength);
status = rdpdr_ignore_capset(TRUE, rdpdr->log, s, capabilityLength);
break;
case CAP_PRINTER_TYPE:
status = rdpdr_ignore_capset(s, capabilityLength);
status = rdpdr_ignore_capset(TRUE, rdpdr->log, s, capabilityLength);
break;
case CAP_PORT_TYPE:
status = rdpdr_ignore_capset(s, capabilityLength);
status = rdpdr_ignore_capset(TRUE, rdpdr->log, s, capabilityLength);
break;
case CAP_DRIVE_TYPE:
status = rdpdr_ignore_capset(s, capabilityLength);
status = rdpdr_ignore_capset(TRUE, rdpdr->log, s, capabilityLength);
break;
case CAP_SMARTCARD_TYPE:
status = rdpdr_ignore_capset(s, capabilityLength);
status = rdpdr_ignore_capset(TRUE, rdpdr->log, s, capabilityLength);
break;
default:
WLog_WARN(TAG, "[%s | %s] invalid capability type 0x%04" PRIx16,
SERVER_RX_LOG(rdpdr->log, WLOG_WARN,
"[%s | %s] invalid capability type 0x%04" PRIx16,
rdpdr_component_string(component), rdpdr_packetid_string(packetid),
capabilityType);
status = ERROR_INVALID_DATA;
@ -757,7 +819,7 @@ static UINT rdpdr_send_client_capability_response(pClientContext* pc,
return CHANNEL_RC_NO_MEMORY;
if (!rdpdr_write_smartcard_capset(&rdpdr->common, s))
return CHANNEL_RC_NO_MEMORY;
return rdpdr_client_send(pc, s);
return rdpdr_client_send(rdpdr->log, pc, s);
}
static UINT rdpdr_send_server_clientid_confirm(pf_channel_server_context* rdpdr)
@ -770,7 +832,6 @@ static UINT rdpdr_send_server_clientid_confirm(pf_channel_server_context* rdpdr)
Stream_Write_UINT16(s, rdpdr->common.versionMajor);
Stream_Write_UINT16(s, rdpdr->common.versionMinor);
Stream_Write_UINT32(s, rdpdr->common.clientID);
WLog_DBG(TAG, "[send] server->client clientID=0x%08" PRIx32, rdpdr->common.clientID);
return rdpdr_seal_send_free_request(rdpdr, s);
}
@ -783,34 +844,36 @@ static UINT rdpdr_process_server_clientid_confirm(pf_channel_client_context* rdp
WINPR_ASSERT(rdpdr);
WINPR_ASSERT(s);
if (!rdpdr_process_server_header(s, RDPDR_CTYP_CORE, PAKID_CORE_CLIENTID_CONFIRM, 8))
if (!rdpdr_process_server_header(FALSE, rdpdr->log, s, RDPDR_CTYP_CORE,
PAKID_CORE_CLIENTID_CONFIRM, 8))
return ERROR_INVALID_DATA;
Stream_Read_UINT16(s, versionMajor);
Stream_Read_UINT16(s, versionMinor);
if (!rdpdr_check_version(versionMajor, versionMinor, RDPDR_CTYP_CORE,
if (!rdpdr_check_version(FALSE, rdpdr->log, versionMajor, versionMinor, RDPDR_CTYP_CORE,
PAKID_CORE_CLIENTID_CONFIRM))
return ERROR_INVALID_DATA;
Stream_Read_UINT32(s, clientID);
WLog_DBG(TAG, "[receive] server->client clientID=0x%08" PRIx32, clientID);
if ((versionMajor != rdpdr->common.versionMajor) ||
(versionMinor != rdpdr->common.versionMinor))
{
WLog_WARN(TAG,
"[%s | %s] Version mismatch, sent %" PRIu16 ".%" PRIu16 ", downgraded to %" PRIu16
".%" PRIu16,
CLIENT_RX_LOG(rdpdr->log, WLOG_WARN,
"[%s | %s] Version mismatch, sent %" PRIu16 ".%" PRIu16
", downgraded to %" PRIu16 ".%" PRIu16,
rdpdr_component_string(RDPDR_CTYP_CORE),
rdpdr_packetid_string(PAKID_CORE_CLIENTID_CONFIRM), rdpdr->common.versionMajor,
rdpdr->common.versionMinor, versionMajor, versionMinor);
rdpdr_packetid_string(PAKID_CORE_CLIENTID_CONFIRM),
rdpdr->common.versionMajor, rdpdr->common.versionMinor, versionMajor,
versionMinor);
rdpdr->common.versionMajor = versionMajor;
rdpdr->common.versionMinor = versionMinor;
}
if (clientID != rdpdr->common.clientID)
{
WLog_WARN(TAG, "[%s | %s] clientID mismatch, sent 0x%08" PRIx32 ", changed to 0x%08" PRIx32,
CLIENT_RX_LOG(rdpdr->log, WLOG_WARN,
"[%s | %s] clientID mismatch, sent 0x%08" PRIx32 ", changed to 0x%08" PRIx32,
rdpdr_component_string(RDPDR_CTYP_CORE),
rdpdr_packetid_string(PAKID_CORE_CLIENTID_CONFIRM), rdpdr->common.clientID,
clientID);
@ -834,17 +897,17 @@ rdpdr_process_server_capability_request_or_clientid_confirm(pf_channel_client_co
if ((rdpdr->flags & mask) == mask)
{
WLog_WARN(TAG, "[%s]: already past this state, abort!", __FUNCTION__);
CLIENT_RX_LOG(rdpdr->log, WLOG_WARN, "[%s]: already past this state, abort!", __FUNCTION__);
return FALSE;
}
if (!Stream_CheckAndLogRequiredLength(TAG, s, 4))
if (!Stream_CheckAndLogRequiredLengthClient(rdpdr->log, s, 4))
return FALSE;
Stream_Read_UINT16(s, component);
if (rcomponent != component)
{
WLog_WARN(TAG, "[%s]: got component %s, expected %s", __FUNCTION__,
CLIENT_RX_LOG(rdpdr->log, WLOG_WARN, "[%s]: got component %s, expected %s", __FUNCTION__,
rdpdr_component_string(component), rdpdr_component_string(rcomponent));
return FALSE;
}
@ -856,8 +919,8 @@ rdpdr_process_server_capability_request_or_clientid_confirm(pf_channel_client_co
case PAKID_CORE_SERVER_CAPABILITY:
if (rdpdr->flags & STATE_CLIENT_EXPECT_SERVER_CORE_CAPABILITY_REQUEST)
{
WLog_WARN(TAG, "[%s]: got duplicate packetid %s", __FUNCTION__,
rdpdr_packetid_string(packetid));
CLIENT_RX_LOG(rdpdr->log, WLOG_WARN, "[%s]: got duplicate packetid %s",
__FUNCTION__, rdpdr_packetid_string(packetid));
return FALSE;
}
rdpdr->flags |= STATE_CLIENT_EXPECT_SERVER_CORE_CAPABILITY_REQUEST;
@ -866,8 +929,8 @@ rdpdr_process_server_capability_request_or_clientid_confirm(pf_channel_client_co
default:
if (rdpdr->flags & STATE_CLIENT_EXPECT_SERVER_CLIENT_ID_CONFIRM)
{
WLog_WARN(TAG, "[%s]: got duplicate packetid %s", __FUNCTION__,
rdpdr_packetid_string(packetid));
CLIENT_RX_LOG(rdpdr->log, WLOG_WARN, "[%s]: got duplicate packetid %s",
__FUNCTION__, rdpdr_packetid_string(packetid));
return FALSE;
}
rdpdr->flags |= STATE_CLIENT_EXPECT_SERVER_CLIENT_ID_CONFIRM;
@ -893,7 +956,7 @@ static UINT rdpdr_send_emulated_scard_device_list_announce_request(pClientContex
Stream_Write_UINT32(s, 6);
Stream_Write(s, "SCARD\0", 6);
return rdpdr_client_send(pc, s);
return rdpdr_client_send(rdpdr->log, pc, s);
}
static UINT rdpdr_send_emulated_scard_device_remove(pClientContext* pc,
@ -909,7 +972,7 @@ static UINT rdpdr_send_emulated_scard_device_remove(pClientContext* pc,
Stream_Write_UINT32(
s, SCARD_DEVICE_ID); /* deviceID -> reserve highest value for the emulated smartcard */
return rdpdr_client_send(pc, s);
return rdpdr_client_send(rdpdr->log, pc, s);
}
static UINT rdpdr_process_server_device_announce_response(pf_channel_client_context* rdpdr,
@ -923,7 +986,7 @@ static UINT rdpdr_process_server_device_announce_response(pf_channel_client_cont
WINPR_ASSERT(rdpdr);
WINPR_ASSERT(s);
if (!rdpdr_process_server_header(s, component, packetid, 8))
if (!rdpdr_process_server_header(TRUE, rdpdr->log, s, component, packetid, 8))
return ERROR_INVALID_DATA;
Stream_Read_UINT32(s, deviceID);
@ -931,18 +994,20 @@ static UINT rdpdr_process_server_device_announce_response(pf_channel_client_cont
if (deviceID != SCARD_DEVICE_ID)
{
WLog_WARN(TAG, "[%s | %s] deviceID mismatch, sent 0x%08" PRIx32 ", changed to 0x%08" PRIx32,
CLIENT_RX_LOG(rdpdr->log, WLOG_WARN,
"[%s | %s] deviceID mismatch, sent 0x%08" PRIx32 ", changed to 0x%08" PRIx32,
rdpdr_component_string(component), rdpdr_packetid_string(packetid),
SCARD_DEVICE_ID, deviceID);
}
else if (resultCode != 0)
{
WLog_WARN(TAG, "[%s | %s] deviceID 0x%08" PRIx32 " resultCode=0x%08" PRIx32,
CLIENT_RX_LOG(rdpdr->log, WLOG_WARN,
"[%s | %s] deviceID 0x%08" PRIx32 " resultCode=0x%08" PRIx32,
rdpdr_component_string(component), rdpdr_packetid_string(packetid), deviceID,
resultCode);
}
else
WLog_DBG(TAG,
CLIENT_RX_LOG(rdpdr->log, WLOG_DEBUG,
"[%s | %s] deviceID 0x%08" PRIx32 " resultCode=0x%08" PRIx32
" -> emulated smartcard redirected!",
rdpdr_component_string(component), rdpdr_packetid_string(packetid), deviceID,
@ -952,8 +1017,10 @@ static UINT rdpdr_process_server_device_announce_response(pf_channel_client_cont
}
#endif
static BOOL pf_channel_rdpdr_client_send_to_server(pServerContext* ps, wStream* s)
static BOOL pf_channel_rdpdr_client_send_to_server(pf_channel_client_context* rdpdr,
pServerContext* ps, wStream* s)
{
WINPR_ASSERT(rdpdr);
if (ps)
{
UINT16 server_channel_id = WTSChannelGetId(ps->context.peer, RDPDR_SVC_CHANNEL_NAME);
@ -964,10 +1031,13 @@ static BOOL pf_channel_rdpdr_client_send_to_server(pServerContext* ps, wStream*
if (server_channel_id == 0)
return TRUE;
size_t len = Stream_Length(s);
Stream_SetPosition(s, len);
rdpdr_dump_send_packet(rdpdr->log, WLOG_TRACE, s, proxy_client_tx);
WINPR_ASSERT(ps->context.peer);
WINPR_ASSERT(ps->context.peer->SendChannelData);
return ps->context.peer->SendChannelData(ps->context.peer, server_channel_id,
Stream_Buffer(s), Stream_Length(s));
Stream_Buffer(s), len);
}
return TRUE;
}
@ -984,7 +1054,7 @@ static BOOL rdpdr_process_server_loggedon_request(pServerContext* ps, pClientCon
return FALSE;
if (rdpdr_send_emulated_scard_device_list_announce_request(pc, rdpdr) != CHANNEL_RC_OK)
return FALSE;
return pf_channel_rdpdr_client_send_to_server(ps, s);
return pf_channel_rdpdr_client_send_to_server(rdpdr, ps, s);
}
static BOOL filter_smartcard_io_requests(pf_channel_client_context* rdpdr, wStream* s,
@ -1074,12 +1144,12 @@ BOOL pf_channel_send_client_queue(pClientContext* pc, pf_channel_client_context*
const size_t len = Stream_Length(s);
Stream_SetPosition(s, len);
rdpdr_dump_send_packet(WLog_Get(TAG), WLOG_TRACE, s, "proxy-client-queue");
rdpdr_dump_send_packet(rdpdr->log, WLOG_TRACE, s, proxy_server_tx " (queue) ");
WINPR_ASSERT(pc->context.instance->SendChannelData);
if (!pc->context.instance->SendChannelData(pc->context.instance, channelId,
Stream_Buffer(s), len))
{
WLog_WARN(TAG, "xxxxxx TODO: Failed to send data!");
CLIENT_TX_LOG(rdpdr->log, WLOG_ERROR, "xxxxxx TODO: Failed to send data!");
}
Stream_Free(s, TRUE);
}
@ -1134,7 +1204,8 @@ BOOL pf_channel_rdpdr_client_handle(pClientContext* pc, UINT16 channelId, const
Stream_SetPosition(s, 0);
if (!Stream_EnsureRemainingCapacity(s, xsize))
{
WLog_ERR(TAG, "[%s]: Channel %s [0x%04" PRIx16 "] not enough memory [need %" PRIuz "]",
CLIENT_RX_LOG(rdpdr->log, WLOG_ERROR,
"[%s]: Channel %s [0x%04" PRIx16 "] not enough memory [need %" PRIuz "]",
__FUNCTION__, channel_name, channelId, xsize);
return FALSE;
}
@ -1146,14 +1217,14 @@ BOOL pf_channel_rdpdr_client_handle(pClientContext* pc, UINT16 channelId, const
Stream_SetPosition(s, 0);
if (Stream_Length(s) != totalSize)
{
WLog_WARN(TAG,
CLIENT_RX_LOG(rdpdr->log, WLOG_WARN,
"Received invalid %s channel data (server -> proxy), expected %" PRIuz
"bytes, got %" PRIuz,
channel_name, totalSize, Stream_Length(s));
return FALSE;
}
rdpdr_dump_received_packet(WLog_Get(TAG), WLOG_TRACE, s, "proxy-client");
rdpdr_dump_received_packet(rdpdr->log, WLOG_TRACE, s, proxy_server_rx);
switch (rdpdr->state)
{
case STATE_CLIENT_EXPECT_SERVER_ANNOUNCE_REQUEST:
@ -1190,7 +1261,7 @@ BOOL pf_channel_rdpdr_client_handle(pClientContext* pc, UINT16 channelId, const
#if defined(WITH_PROXY_EMULATE_SMARTCARD)
if (!pf_channel_smartcard_client_emulate(pc) ||
!filter_smartcard_io_requests(rdpdr, s, &packetid))
return pf_channel_rdpdr_client_send_to_server(ps, s);
return pf_channel_rdpdr_client_send_to_server(rdpdr, ps, s);
else
{
switch (packetid)
@ -1204,11 +1275,12 @@ BOOL pf_channel_rdpdr_client_handle(pClientContext* pc, UINT16 channelId, const
rdpdr, RDPDR_CTYP_CORE, PAKID_CORE_DEVICE_IOCOMPLETION, 0);
WINPR_ASSERT(out);
if (!rdpdr_process_server_header(s, RDPDR_CTYP_CORE,
if (!rdpdr_process_server_header(FALSE, rdpdr->log, s, RDPDR_CTYP_CORE,
PAKID_CORE_DEVICE_IOREQUEST, 20))
return FALSE;
if (!pf_channel_smartcard_client_handle(pc, s, out, rdpdr_client_send))
if (!pf_channel_smartcard_client_handle(rdpdr->log, pc, s, out,
rdpdr_client_send))
return FALSE;
}
break;
@ -1225,7 +1297,8 @@ BOOL pf_channel_rdpdr_client_handle(pClientContext* pc, UINT16 channelId, const
case PAKID_CORE_DEVICE_REPLY:
break;
default:
WLog_ERR(TAG,
CLIENT_RX_LOG(
rdpdr->log, WLOG_ERROR,
"[%s]: Channel %s [0x%04" PRIx16
"] we´ve reached an impossible state %s! [%s] aliens invaded!",
__FUNCTION__, channel_name, channelId,
@ -1236,10 +1309,10 @@ BOOL pf_channel_rdpdr_client_handle(pClientContext* pc, UINT16 channelId, const
}
break;
#else
return pf_channel_rdpdr_client_send_to_server(ps, s);
return pf_channel_rdpdr_client_send_to_server(rdpdr, ps, s);
#endif
default:
WLog_ERR(TAG,
CLIENT_RX_LOG(rdpdr->log, WLOG_ERROR,
"[%s]: Channel %s [0x%04" PRIx16
"] we´ve reached an impossible state %s! aliens invaded!",
__FUNCTION__, channel_name, channelId,
@ -1489,6 +1562,7 @@ BOOL pf_channel_rdpdr_client_new(pClientContext* pc)
rdpdr = calloc(1, sizeof(pf_channel_client_context));
if (!rdpdr)
return FALSE;
rdpdr->log = WLog_Get(TAG);
if (!pf_channel_rdpdr_common_context_new(&rdpdr->common, pf_channel_rdpdr_client_context_free))
goto fail;
@ -1540,6 +1614,7 @@ BOOL pf_channel_rdpdr_server_new(pServerContext* ps)
rdpdr = calloc(1, sizeof(pf_channel_server_context));
if (!rdpdr)
return FALSE;
rdpdr->log = WLog_Get(TAG);
if (!pf_channel_rdpdr_common_context_new(&rdpdr->common, pf_channel_rdpdr_server_context_free))
goto fail;
rdpdr->state = STATE_SERVER_INITIAL;
@ -1572,7 +1647,7 @@ void pf_channel_rdpdr_server_free(pServerContext* ps)
HashTable_Remove(ps->interceptContextMap, RDPDR_SVC_CHANNEL_NAME);
}
static pf_channel_server_context* get_channel(pServerContext* ps)
static pf_channel_server_context* get_channel(pServerContext* ps, BOOL send)
{
pf_channel_server_context* rdpdr;
WINPR_ASSERT(ps);
@ -1581,7 +1656,8 @@ static pf_channel_server_context* get_channel(pServerContext* ps)
rdpdr = HashTable_GetItemValue(ps->interceptContextMap, RDPDR_SVC_CHANNEL_NAME);
if (!rdpdr)
{
WLog_ERR(TAG, "[%s]: Channel %s missing context in interceptContextMap", __FUNCTION__,
SERVER_RXTX_LOG(send, rdpdr->log, WLOG_ERROR,
"[%s]: Channel %s missing context in interceptContextMap", __FUNCTION__,
RDPDR_SVC_CHANNEL_NAME);
return NULL;
}
@ -1594,7 +1670,7 @@ BOOL pf_channel_rdpdr_server_handle(pServerContext* ps, UINT16 channelId, const
{
wStream* s;
pClientContext* pc;
pf_channel_server_context* rdpdr = get_channel(ps);
pf_channel_server_context* rdpdr = get_channel(ps, FALSE);
if (!rdpdr)
return FALSE;
@ -1618,13 +1694,14 @@ BOOL pf_channel_rdpdr_server_handle(pServerContext* ps, UINT16 channelId, const
if (Stream_Length(s) != totalSize)
{
WLog_WARN(TAG,
SERVER_RX_LOG(rdpdr->log, WLOG_WARN,
"Received invalid %s channel data (client -> proxy), expected %" PRIuz
"bytes, got %" PRIuz,
channel_name, totalSize, Stream_Length(s));
return FALSE;
}
rdpdr_dump_received_packet(rdpdr->log, WLOG_TRACE, s, proxy_client_rx);
switch (rdpdr->state)
{
case STATE_SERVER_EXPECT_CLIENT_ANNOUNCE_REPLY:
@ -1663,7 +1740,8 @@ BOOL pf_channel_rdpdr_server_handle(pServerContext* ps, UINT16 channelId, const
break;
default:
case STATE_SERVER_INITIAL:
WLog_WARN(TAG, "Invalid state %s", rdpdr_server_state_to_string(rdpdr->state));
SERVER_RX_LOG(rdpdr->log, WLOG_WARN, "Invalid state %s",
rdpdr_server_state_to_string(rdpdr->state));
return FALSE;
}
@ -1672,7 +1750,7 @@ BOOL pf_channel_rdpdr_server_handle(pServerContext* ps, UINT16 channelId, const
BOOL pf_channel_rdpdr_server_announce(pServerContext* ps)
{
pf_channel_server_context* rdpdr = get_channel(ps);
pf_channel_server_context* rdpdr = get_channel(ps, TRUE);
if (!rdpdr)
return FALSE;
@ -1712,10 +1790,7 @@ static PfChannelResult pf_rdpdr_back_data(proxyData* pdata,
if (!pf_channel_rdpdr_client_handle(pdata->pc, channel->back_channel_id, channel->channel_name,
xdata, xsize, flags, totalSize))
{
WLog_ERR(TAG, "error treating client back data");
return PF_CHANNEL_RESULT_ERROR;
}
#if defined(WITH_PROXY_EMULATE_SMARTCARD)
if (pf_channel_smartcard_client_emulate(pdata->pc))
@ -1734,10 +1809,7 @@ static PfChannelResult pf_rdpdr_front_data(proxyData* pdata,
if (!pf_channel_rdpdr_server_handle(pdata->ps, channel->front_channel_id, channel->channel_name,
xdata, xsize, flags, totalSize))
{
WLog_ERR(TAG, "error treating front data");
return PF_CHANNEL_RESULT_ERROR;
}
#if defined(WITH_PROXY_EMULATE_SMARTCARD)
if (pf_channel_smartcard_client_emulate(pdata->pc))

13
server/proxy/channels/pf_channel_smartcard.c
View File

@ -54,7 +54,8 @@ typedef struct
SMARTCARD_OPERATION op;
wStream* out;
pClientContext* pc;
UINT (*send_fkt)(pClientContext*, wStream*);
wLog* log;
pf_scard_send_fkt_t send_fkt;
} pf_channel_client_queue_element;
static pf_channel_client_context* scard_get_client_context(pClientContext* pc)
@ -121,7 +122,7 @@ static VOID irp_thread(PTP_CALLBACK_INSTANCE Instance, PVOID Context, PTP_WORK W
if (rc == CHANNEL_RC_OK)
{
if (pf_channel_client_write_iostatus(arg->e->out, &arg->e->op, ioStatus))
arg->e->send_fkt(arg->e->pc, arg->e->out);
arg->e->send_fkt(arg->e->log, arg->e->pc, arg->e->out);
}
}
queue_free(arg->e);
@ -156,8 +157,8 @@ fail:
return FALSE;
}
BOOL pf_channel_smartcard_client_handle(pClientContext* pc, wStream* s, wStream* out,
UINT (*send_fkt)(pClientContext*, wStream*))
BOOL pf_channel_smartcard_client_handle(wLog* log, pClientContext* pc, wStream* s, wStream* out,
pf_scard_send_fkt_t send_fkt)
{
BOOL rc = FALSE;
LONG status;
@ -167,12 +168,14 @@ BOOL pf_channel_smartcard_client_handle(pClientContext* pc, wStream* s, wStream*
pf_channel_client_queue_element e = { 0 };
pf_channel_client_context* scard = scard_get_client_context(pc);
WINPR_ASSERT(log);
WINPR_ASSERT(send_fkt);
WINPR_ASSERT(s);
if (!scard)
return FALSE;
e.log = log;
e.pc = pc;
e.out = out;
e.send_fkt = send_fkt;
@ -247,7 +250,7 @@ BOOL pf_channel_smartcard_client_handle(pClientContext* pc, wStream* s, wStream*
break;
}
rc = send_fkt(pc, out) == CHANNEL_RC_OK;
rc = send_fkt(log, pc, out) == CHANNEL_RC_OK;
fail:
smartcard_operation_free(&e.op, FALSE);

7
server/proxy/channels/pf_channel_smartcard.h
View File

@ -21,16 +21,19 @@
#ifndef FREERDP_SERVER_PROXY_SCARD_H
#define FREERDP_SERVER_PROXY_SCARD_H
#include <winpr/wlog.h>
#include <freerdp/server/proxy/proxy_context.h>
typedef UINT (*pf_scard_send_fkt_t)(wLog* log, pClientContext*, wStream*);
BOOL pf_channel_smartcard_client_new(pClientContext* pc);
void pf_channel_smartcard_client_free(pClientContext* pc);
BOOL pf_channel_smartcard_client_reset(pClientContext* pc);
BOOL pf_channel_smartcard_client_emulate(pClientContext* pc);
BOOL pf_channel_smartcard_client_handle(pClientContext* pc, wStream* s, wStream* out,
UINT (*send_fkt)(pClientContext*, wStream*));
BOOL pf_channel_smartcard_client_handle(wLog* log, pClientContext* pc, wStream* s, wStream* out,
pf_scard_send_fkt_t fkt);
BOOL pf_channel_smartcard_server_handle(pServerContext* ps, wStream* s);
#endif /* FREERDP_SERVER_PROXY_SCARD_H */