channels/smartcard: added detailed debug tracing

diff --git a/channels/smartcard/client/smartcard_main.c b/channels/smartcard/client/smartcard_main.c
index 0d575dd..84ee581 100644 (file)
--- a/channels/smartcard/client/smartcard_main.c
+++ b/channels/smartcard/client/smartcard_main.c
@@ -255,6 +255,8 @@ int DeviceServiceEntry(PDEVICE_SERVICE_ENTRY_POINTS pEntryPoints)
 
        smartcard->log = WLog_Get("com.freerdp.channel.smartcard.client");
 
+       WLog_SetLogLevel(smartcard->log, WLOG_DEBUG);
+
        smartcard->IrpQueue = MessageQueue_New(NULL);
        smartcard->OutstandingIrps = ListDictionary_New(TRUE);
 

diff --git a/channels/smartcard/client/smartcard_operations.c b/channels/smartcard/client/smartcard_operations.c
index 7110683..77f0b81 100644 (file)
--- a/channels/smartcard/client/smartcard_operations.c
+++ b/channels/smartcard/client/smartcard_operations.c
@@ -180,13 +180,17 @@ static UINT32 smartcard_EstablishContext(SMARTCARD_DEVICE* smartcard, IRP* irp)
 
        status = smartcard_unpack_establish_context_call(smartcard, irp->input, &call);
 
+       smartcard_trace_establish_context_call(smartcard, &call);
+
        if (status)
                return status;
 
        status = ret.ReturnCode = SCardEstablishContext(call.dwScope, NULL, NULL, &hContext);
 
-       ret.Context.cbContext = sizeof(ULONG_PTR);
        ret.Context.pbContext = (UINT64) hContext;
+       ret.Context.cbContext = sizeof(ULONG_PTR);
+
+       smartcard_trace_establish_context_return(smartcard, &ret);
 
        status = smartcard_pack_establish_context_return(smartcard, irp->output, &ret);
 
@@ -205,6 +209,13 @@ static UINT32 smartcard_ReleaseContext(SMARTCARD_DEVICE* smartcard, IRP* irp)
 
        status = smartcard_unpack_context_call(smartcard, irp->input, &call);
 
+       WLog_Print(smartcard->log, WLOG_DEBUG, "ReleaseContext_Call {");
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "hContext: 0x%08X (%d)",
+               call.Context.pbContext, call.Context.cbContext);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "}");
+
        if (status)
                return status;
 
@@ -224,6 +235,13 @@ static UINT32 smartcard_IsValidContext(SMARTCARD_DEVICE* smartcard, IRP* irp)
 
        status = smartcard_unpack_context_call(smartcard, irp->input, &call);
 
+       WLog_Print(smartcard->log, WLOG_DEBUG, "IsValidContext_Call {");
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "hContext: 0x%08X (%d)",
+               call.Context.pbContext, call.Context.cbContext);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "}");
+
        if (status)
                return status;
 
@@ -245,6 +263,8 @@ static UINT32 smartcard_ListReadersA(SMARTCARD_DEVICE* smartcard, IRP* irp)
 
        status = smartcard_unpack_list_readers_call(smartcard, irp->input, &call);
 
+       smartcard_trace_list_readers_call(smartcard, &call);
+
        if (status)
                return status;
 
@@ -260,6 +280,8 @@ static UINT32 smartcard_ListReadersA(SMARTCARD_DEVICE* smartcard, IRP* irp)
        if (status)
                return status;
 
+       smartcard_trace_list_readers_return(smartcard, &ret);
+
        status = smartcard_pack_list_readers_return(smartcard, irp->output, &ret);
 
        if (status)
@@ -285,6 +307,8 @@ static UINT32 smartcard_ListReadersW(SMARTCARD_DEVICE* smartcard, IRP* irp)
 
        status = smartcard_unpack_list_readers_call(smartcard, irp->input, &call);
 
+       smartcard_trace_list_readers_call(smartcard, &call);
+
        if (status)
                return status;
 
@@ -300,6 +324,8 @@ static UINT32 smartcard_ListReadersW(SMARTCARD_DEVICE* smartcard, IRP* irp)
        if (status)
                return status;
 
+       smartcard_trace_list_readers_return(smartcard, &ret);
+
        status = smartcard_pack_list_readers_return(smartcard, irp->output, &ret);
 
        if (status)
@@ -325,6 +351,8 @@ static UINT32 smartcard_GetStatusChangeA(SMARTCARD_DEVICE* smartcard, IRP* irp)
 
        status = smartcard_unpack_get_status_change_a_call(smartcard, irp->input, &call);
 
+       smartcard_trace_get_status_change_a_call(smartcard, &call);
+
        if (status)
                return status;
 
@@ -346,6 +374,8 @@ static UINT32 smartcard_GetStatusChangeA(SMARTCARD_DEVICE* smartcard, IRP* irp)
                CopyMemory(&ret.rgReaderStates[index].rgbAtr, &call.rgReaderStates[index].rgbAtr, 32);
        }
 
+       smartcard_trace_get_status_change_return(smartcard, &ret);
+
        status = smartcard_pack_get_status_change_return(smartcard, irp->output, &ret);
 
        if (status)
@@ -379,6 +409,8 @@ static UINT32 smartcard_GetStatusChangeW(SMARTCARD_DEVICE* smartcard, IRP* irp)
 
        status = smartcard_unpack_get_status_change_w_call(smartcard, irp->input, &call);
 
+       smartcard_trace_get_status_change_w_call(smartcard, &call);
+
        if (status)
                return status;
 
@@ -400,6 +432,8 @@ static UINT32 smartcard_GetStatusChangeW(SMARTCARD_DEVICE* smartcard, IRP* irp)
                CopyMemory(&ret.rgReaderStates[index].rgbAtr, &call.rgReaderStates[index].rgbAtr, 32);
        }
 
+       smartcard_trace_get_status_change_return(smartcard, &ret);
+
        status = smartcard_pack_get_status_change_return(smartcard, irp->output, &ret);
 
        if (status)
@@ -431,6 +465,13 @@ static UINT32 smartcard_Cancel(SMARTCARD_DEVICE* smartcard, IRP* irp)
 
        status = smartcard_unpack_context_call(smartcard, irp->input, &call);
 
+       WLog_Print(smartcard->log, WLOG_DEBUG, "Cancel_Call {");
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "hContext: 0x%08X (%d)",
+               call.Context.pbContext, call.Context.cbContext);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "}");
+
        if (status)
                return status;
 
@@ -453,6 +494,8 @@ UINT32 smartcard_ConnectA(SMARTCARD_DEVICE* smartcard, IRP* irp)
 
        status = smartcard_unpack_connect_a_call(smartcard, irp->input, &call);
 
+       smartcard_trace_connect_a_call(smartcard, &call);
+
        if (status)
                return status;
 
@@ -470,11 +513,13 @@ UINT32 smartcard_ConnectA(SMARTCARD_DEVICE* smartcard, IRP* irp)
        if (status)
                return status;
 
-       ret.hCard.Context.cbContext = sizeof(ULONG_PTR);
        ret.hCard.Context.pbContext = (UINT64) hContext;
+       ret.hCard.Context.cbContext = sizeof(ULONG_PTR);
 
-       ret.hCard.cbHandle = sizeof(ULONG_PTR);
        ret.hCard.pbHandle = (UINT64) hCard;
+       ret.hCard.cbHandle = sizeof(ULONG_PTR);
+
+       smartcard_trace_connect_return(smartcard, &ret);
 
        status = smartcard_pack_connect_return(smartcard, irp->output, &ret);
 
@@ -499,6 +544,8 @@ UINT32 smartcard_ConnectW(SMARTCARD_DEVICE* smartcard, IRP* irp)
 
        status = smartcard_unpack_connect_w_call(smartcard, irp->input, &call);
 
+       smartcard_trace_connect_w_call(smartcard, &call);
+
        if (status)
                return status;
 
@@ -516,11 +563,13 @@ UINT32 smartcard_ConnectW(SMARTCARD_DEVICE* smartcard, IRP* irp)
        if (status)
                return status;
 
-       ret.hCard.Context.cbContext = sizeof(ULONG_PTR);
        ret.hCard.Context.pbContext = (UINT64) hContext;
+       ret.hCard.Context.cbContext = sizeof(ULONG_PTR);
 
-       ret.hCard.cbHandle = sizeof(ULONG_PTR);
        ret.hCard.pbHandle = (UINT64) hCard;
+       ret.hCard.cbHandle = sizeof(ULONG_PTR);
+
+       smartcard_trace_connect_return(smartcard, &ret);
 
        status = smartcard_pack_connect_return(smartcard, irp->output, &ret);
 
@@ -573,6 +622,15 @@ static UINT32 smartcard_Disconnect(SMARTCARD_DEVICE* smartcard, IRP* irp)
 
        status = smartcard_unpack_hcard_and_disposition_call(smartcard, irp->input, &call);
 
+       WLog_Print(smartcard->log, WLOG_DEBUG, "Cancel_Call {");
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "hContext: 0x%08X (%d) hCard: 0x%08X (%d)",
+               call.hCard.Context.pbContext, call.hCard.Context.cbContext, call.hCard.pbHandle, call.hCard.pbHandle);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "dwDisposition: 0x%08X", call.dwDisposition);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "}");
+
        if (status)
                return status;
 
@@ -597,6 +655,15 @@ static UINT32 smartcard_BeginTransaction(SMARTCARD_DEVICE* smartcard, IRP* irp)
 
        status = smartcard_unpack_hcard_and_disposition_call(smartcard, irp->input, &call);
 
+       WLog_Print(smartcard->log, WLOG_DEBUG, "BeginTransaction_Call {");
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "hContext: 0x%08X (%d) hCard: 0x%08X (%d)",
+               call.hCard.Context.pbContext, call.hCard.Context.cbContext, call.hCard.pbHandle, call.hCard.pbHandle);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "dwDisposition: 0x%08X", call.dwDisposition);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "}");
+
        if (status)
                return status;
 
@@ -621,6 +688,15 @@ static UINT32 smartcard_EndTransaction(SMARTCARD_DEVICE* smartcard, IRP* irp)
 
        status = smartcard_unpack_hcard_and_disposition_call(smartcard, irp->input, &call);
 
+       WLog_Print(smartcard->log, WLOG_DEBUG, "EndTransaction_Call {");
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "hContext: 0x%08X (%d) hCard: 0x%08X (%d)",
+               call.hCard.Context.pbContext, call.hCard.Context.cbContext, call.hCard.pbHandle, call.hCard.pbHandle);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "dwDisposition: 0x%08X", call.dwDisposition);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "}");
+
        if (status)
                return status;
 

diff --git a/channels/smartcard/client/smartcard_pack.c b/channels/smartcard/client/smartcard_pack.c
index 4398a11..f0ffe8f 100644 (file)
--- a/channels/smartcard/client/smartcard_pack.c
+++ b/channels/smartcard/client/smartcard_pack.c
@@ -406,6 +406,18 @@ UINT32 smartcard_unpack_establish_context_call(SMARTCARD_DEVICE* smartcard, wStr
        return SCARD_S_SUCCESS;
 }
 
+void smartcard_trace_establish_context_call(SMARTCARD_DEVICE* smartcard, EstablishContext_Call* call)
+{
+       if (!WLog_IsLevelActive(smartcard->log, WLOG_DEBUG))
+               return;
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "EstablishContext_Call {");
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "dwScope: 0x%08X", call->dwScope);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "}");
+}
+
 UINT32 smartcard_pack_establish_context_return(SMARTCARD_DEVICE* smartcard, wStream* s, EstablishContext_Return* ret)
 {
        UINT32 status;
@@ -423,6 +435,21 @@ UINT32 smartcard_pack_establish_context_return(SMARTCARD_DEVICE* smartcard, wStr
        return SCARD_S_SUCCESS;
 }
 
+void smartcard_trace_establish_context_return(SMARTCARD_DEVICE* smartcard, EstablishContext_Return* ret)
+{
+       if (!WLog_IsLevelActive(smartcard->log, WLOG_DEBUG))
+               return;
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "EstablishContext_Call {");
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "ReturnCode: 0x%08X", ret->ReturnCode);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "hContext: 0x%08X (%d)",
+               ret->Context.pbContext, ret->Context.cbContext);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "}");
+}
+
 UINT32 smartcard_unpack_context_call(SMARTCARD_DEVICE* smartcard, wStream* s, Context_Call* call)
 {
        UINT32 status;
@@ -513,6 +540,34 @@ UINT32 smartcard_unpack_list_readers_call(SMARTCARD_DEVICE* smartcard, wStream*
        return SCARD_S_SUCCESS;
 }
 
+void smartcard_trace_list_readers_call(SMARTCARD_DEVICE* smartcard, ListReaders_Call* call)
+{
+       BOOL unicode;
+       char* mszGroupsA = NULL;
+
+       if (!WLog_IsLevelActive(smartcard->log, WLOG_DEBUG))
+               return;
+
+       unicode = ((call->cBytes > 2) && !call->mszGroups[1]) ? TRUE : FALSE;
+
+       if (unicode)
+               ConvertFromUnicode(CP_UTF8, 0, (WCHAR*) call->mszGroups, call->cBytes / 2, &mszGroupsA, 0, NULL, NULL);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "ListReaders_Call {");
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "hContext: 0x%08X (%d)",
+               call->Context.pbContext, call->Context.cbContext);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG,
+               "cBytes: %d mszGroups: %s fmszReadersIsNULL: %d cchReaders: 0x%08X",
+               call->cBytes, mszGroupsA, call->fmszReadersIsNULL, call->cchReaders);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "}");
+
+       if (unicode)
+               free(mszGroupsA);
+}
+
 UINT32 smartcard_pack_list_readers_return(SMARTCARD_DEVICE* smartcard, wStream* s, ListReaders_Return* ret)
 {
        UINT32 mszNdrPtr;
@@ -537,6 +592,47 @@ UINT32 smartcard_pack_list_readers_return(SMARTCARD_DEVICE* smartcard, wStream*
        return SCARD_S_SUCCESS;
 }
 
+void smartcard_trace_list_readers_return(SMARTCARD_DEVICE* smartcard, ListReaders_Return* ret)
+{
+       int index;
+       int length;
+       BOOL unicode;
+       char* mszA = NULL;
+
+       if (!WLog_IsLevelActive(smartcard->log, WLOG_DEBUG))
+               return;
+
+       unicode = ((ret->cBytes > 2) && !ret->msz[1]) ? TRUE : FALSE;
+
+       if (unicode)
+       {
+               length = ret->cBytes / 2;
+               ConvertFromUnicode(CP_UTF8, 0, (WCHAR*) ret->msz, length, &mszA, 0, NULL, NULL);
+       }
+       else
+       {
+               length = ret->cBytes;
+               mszA = (char*) malloc(length);
+               CopyMemory(mszA, ret->msz, ret->cBytes);
+       }
+
+       for (index = 0; index < length - 2; index++)
+       {
+               if (mszA[index] == '\0')
+                       mszA[index] = ',';
+       }
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "ListReaders_Return {");
+
+       WLog_Print(smartcard->log, WLOG_DEBUG,
+               "ReturnCode: 0x%08X cBytes: %d msz: %s",
+               ret->ReturnCode, ret->cBytes, mszA);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "}");
+
+       free(mszA);
+}
+
 UINT32 smartcard_unpack_connect_common(SMARTCARD_DEVICE* smartcard, wStream* s, Connect_Common* common)
 {
        UINT32 status;
@@ -586,7 +682,7 @@ UINT32 smartcard_unpack_connect_a_call(SMARTCARD_DEVICE* smartcard, wStream* s,
        Stream_Seek_UINT32(s); /* NdrOffset (4 bytes) */
        Stream_Read_UINT32(s, count); /* NdrActualCount (4 bytes) */
 
-       call->szReader = malloc(count + 1);
+       call->szReader = (unsigned char*) malloc(count + 1);
        Stream_Read(s, call->szReader, count);
        smartcard_unpack_read_size_align(smartcard, s, count, 4);
        call->szReader[count] = '\0';
@@ -596,6 +692,22 @@ UINT32 smartcard_unpack_connect_a_call(SMARTCARD_DEVICE* smartcard, wStream* s,
        return SCARD_S_SUCCESS;
 }
 
+void smartcard_trace_connect_a_call(SMARTCARD_DEVICE* smartcard, ConnectA_Call* call)
+{
+       if (!WLog_IsLevelActive(smartcard->log, WLOG_DEBUG))
+               return;
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "ConnectA_Call {");
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "hContext: 0x%08X (%d)",
+               call->Common.Context.pbContext, call->Common.Context.cbContext);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "szReader: %s dwShareMode: 0x%08X dwPreferredProtocols: 0x%08X",
+               call->szReader, call->Common.dwShareMode, call->Common.dwPreferredProtocols);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "}");
+}
+
 UINT32 smartcard_unpack_connect_w_call(SMARTCARD_DEVICE* smartcard, wStream* s, ConnectW_Call* call)
 {
        UINT32 status;
@@ -623,7 +735,7 @@ UINT32 smartcard_unpack_connect_w_call(SMARTCARD_DEVICE* smartcard, wStream* s,
        Stream_Seek_UINT32(s); /* NdrOffset (4 bytes) */
        Stream_Read_UINT32(s, count); /* NdrActualCount (4 bytes) */
 
-       call->szReader = malloc((count + 1) * 2);
+       call->szReader = (WCHAR*) malloc((count + 1) * 2);
        Stream_Read(s, call->szReader, (count * 2));
        smartcard_unpack_read_size_align(smartcard, s, (count * 2), 4);
        call->szReader[count] = '\0';
@@ -633,6 +745,28 @@ UINT32 smartcard_unpack_connect_w_call(SMARTCARD_DEVICE* smartcard, wStream* s,
        return SCARD_S_SUCCESS;
 }
 
+void smartcard_trace_connect_w_call(SMARTCARD_DEVICE* smartcard, ConnectW_Call* call)
+{
+       char* szReaderA = NULL;
+
+       if (!WLog_IsLevelActive(smartcard->log, WLOG_DEBUG))
+               return;
+
+       ConvertFromUnicode(CP_UTF8, 0, call->szReader, -1, &szReaderA, 0, NULL, NULL);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "ConnectA_Call {");
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "hContext: 0x%08X (%d)",
+               call->Common.Context.pbContext, call->Common.Context.cbContext);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "szReader: %s dwShareMode: 0x%08X dwPreferredProtocols: %d",
+               szReaderA, call->Common.dwShareMode, call->Common.dwPreferredProtocols);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "}");
+
+       free(szReaderA);
+}
+
 UINT32 smartcard_pack_connect_return(SMARTCARD_DEVICE* smartcard, wStream* s, Connect_Return* ret)
 {
        UINT32 status;
@@ -652,6 +786,22 @@ UINT32 smartcard_pack_connect_return(SMARTCARD_DEVICE* smartcard, wStream* s, Co
        return SCARD_S_SUCCESS;
 }
 
+void smartcard_trace_connect_return(SMARTCARD_DEVICE* smartcard, Connect_Return* ret)
+{
+       if (!WLog_IsLevelActive(smartcard->log, WLOG_DEBUG))
+               return;
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "Connect_Return {");
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "hContext: 0x%08X (%d) hCard: 0x%08X (%d)",
+               ret->hCard.Context.pbContext, ret->hCard.Context.cbContext, ret->hCard.pbHandle, ret->hCard.cbHandle);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "dwActiveProtocol: 0x%08X",
+               ret->dwActiveProtocol);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "}");
+}
+
 UINT32 smartcard_unpack_reconnect_call(SMARTCARD_DEVICE* smartcard, wStream* s, Reconnect_Call* call)
 {
        UINT32 status;
@@ -830,6 +980,35 @@ UINT32 smartcard_unpack_get_status_change_a_call(SMARTCARD_DEVICE* smartcard, wS
        return SCARD_S_SUCCESS;
 }
 
+void smartcard_trace_get_status_change_a_call(SMARTCARD_DEVICE* smartcard, GetStatusChangeA_Call* call)
+{
+       UINT32 index;
+       LPSCARD_READERSTATEA readerState;
+
+       if (!WLog_IsLevelActive(smartcard->log, WLOG_DEBUG))
+               return;
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "GetStatusChangeA_Call {");
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "hContext: 0x%08X (%d)",
+               call->Context.pbContext, call->Context.cbContext);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "dwTimeOut: 0x%08X cReaders: %d",
+               call->dwTimeOut, call->cReaders);
+
+       for (index = 0; index < call->cReaders; index++)
+       {
+               readerState = &call->rgReaderStates[index];
+
+               WLog_Print(smartcard->log, WLOG_DEBUG,
+                       "\t[%d]: szReader: %s dwCurrentState: 0x%08X dwEventState: 0x%08X cbAtr: %d",
+                       index, readerState->szReader, readerState->dwCurrentState,
+                       readerState->dwEventState, readerState->cbAtr);
+       }
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "}");
+}
+
 UINT32 smartcard_unpack_get_status_change_w_call(SMARTCARD_DEVICE* smartcard, wStream* s, GetStatusChangeW_Call* call)
 {
        UINT32 index;
@@ -939,6 +1118,41 @@ UINT32 smartcard_unpack_get_status_change_w_call(SMARTCARD_DEVICE* smartcard, wS
        return SCARD_S_SUCCESS;
 }
 
+void smartcard_trace_get_status_change_w_call(SMARTCARD_DEVICE* smartcard, GetStatusChangeW_Call* call)
+{
+       UINT32 index;
+       LPSCARD_READERSTATEW readerState;
+
+       if (!WLog_IsLevelActive(smartcard->log, WLOG_DEBUG))
+               return;
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "GetStatusChangeW_Call {");
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "hContext: 0x%08X (%d)",
+               call->Context.pbContext, call->Context.cbContext);
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "dwTimeOut: 0x%08X cReaders: %d",
+               call->dwTimeOut, call->cReaders);
+
+       for (index = 0; index < call->cReaders; index++)
+       {
+               char* szReaderA = NULL;
+
+               readerState = &call->rgReaderStates[index];
+
+               ConvertFromUnicode(CP_UTF8, 0, readerState->szReader, -1, &szReaderA, 0, NULL, NULL);
+
+               WLog_Print(smartcard->log, WLOG_DEBUG,
+                       "\t[%d]: szReader: %s dwCurrentState: 0x%08X dwEventState: 0x%08X cbAtr: %d",
+                       index, szReaderA, readerState->dwCurrentState,
+                       readerState->dwEventState, readerState->cbAtr);
+
+               free(szReaderA);
+       }
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "}");
+}
+
 UINT32 smartcard_pack_get_status_change_return(SMARTCARD_DEVICE* smartcard, wStream* s, GetStatusChange_Return* ret)
 {
        UINT32 index;
@@ -961,6 +1175,31 @@ UINT32 smartcard_pack_get_status_change_return(SMARTCARD_DEVICE* smartcard, wStr
        return SCARD_S_SUCCESS;
 }
 
+void smartcard_trace_get_status_change_return(SMARTCARD_DEVICE* smartcard, GetStatusChange_Return* ret)
+{
+       UINT32 index;
+       ReaderState_Return* rgReaderState;
+
+       if (!WLog_IsLevelActive(smartcard->log, WLOG_DEBUG))
+               return;
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "GetStatusChange_Return {");
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "ReturnCode: 0x%08X cReaders: %d",
+               ret->ReturnCode, ret->cReaders);
+
+       for (index = 0; index < ret->cReaders; index++)
+       {
+               rgReaderState = &(ret->rgReaderStates[index]);
+
+               WLog_Print(smartcard->log, WLOG_DEBUG,
+                       "\t[%d]: dwCurrentState: 0x%08X dwEventState: 0x%08X cbAtr: %d",
+                       index, rgReaderState->dwCurrentState, rgReaderState->dwEventState, rgReaderState->cbAtr);
+       }
+
+       WLog_Print(smartcard->log, WLOG_DEBUG, "}");
+}
+
 UINT32 smartcard_unpack_state_call(SMARTCARD_DEVICE* smartcard, wStream* s, State_Call* call)
 {
        UINT32 status;

diff --git a/channels/smartcard/client/smartcard_pack.h b/channels/smartcard/client/smartcard_pack.h
index da6fed4..98f60d3 100644 (file)
--- a/channels/smartcard/client/smartcard_pack.h
+++ b/channels/smartcard/client/smartcard_pack.h
@@ -445,17 +445,27 @@ UINT32 smartcard_unpack_redir_scard_handle_ref(SMARTCARD_DEVICE* smartcard, wStr
 UINT32 smartcard_pack_redir_scard_handle_ref(SMARTCARD_DEVICE* smartcard, wStream* s, REDIR_SCARDHANDLE* handle);
 
 UINT32 smartcard_unpack_establish_context_call(SMARTCARD_DEVICE* smartcard, wStream* s, EstablishContext_Call* call);
+void smartcard_trace_establish_context_call(SMARTCARD_DEVICE* smartcard, EstablishContext_Call* call);
+
 UINT32 smartcard_pack_establish_context_return(SMARTCARD_DEVICE* smartcard, wStream* s, EstablishContext_Return* ret);
+void smartcard_trace_establish_context_return(SMARTCARD_DEVICE* smartcard, EstablishContext_Return* ret);
 
 UINT32 smartcard_unpack_context_call(SMARTCARD_DEVICE* smartcard, wStream* s, Context_Call* call);
 
 UINT32 smartcard_unpack_list_readers_call(SMARTCARD_DEVICE* smartcard, wStream* s, ListReaders_Call* call);
+void smartcard_trace_list_readers_call(SMARTCARD_DEVICE* smartcard, ListReaders_Call* call);
+
 UINT32 smartcard_pack_list_readers_return(SMARTCARD_DEVICE* smartcard, wStream* s, ListReaders_Return* ret);
+void smartcard_trace_list_readers_return(SMARTCARD_DEVICE* smartcard, ListReaders_Return* ret);
 
 UINT32 smartcard_unpack_connect_a_call(SMARTCARD_DEVICE* smartcard, wStream* s, ConnectA_Call* call);
+void smartcard_trace_connect_a_call(SMARTCARD_DEVICE* smartcard, ConnectA_Call* call);
+
 UINT32 smartcard_unpack_connect_w_call(SMARTCARD_DEVICE* smartcard, wStream* s, ConnectW_Call* call);
+void smartcard_trace_connect_w_call(SMARTCARD_DEVICE* smartcard, ConnectW_Call* call);
 
 UINT32 smartcard_pack_connect_return(SMARTCARD_DEVICE* smartcard, wStream* s, Connect_Return* ret);
+void smartcard_trace_connect_return(SMARTCARD_DEVICE* smartcard, Connect_Return* ret);
 
 UINT32 smartcard_unpack_reconnect_call(SMARTCARD_DEVICE* smartcard, wStream* s, Reconnect_Call* call);
 UINT32 smartcard_pack_reconnect_return(SMARTCARD_DEVICE* smartcard, wStream* s, Reconnect_Return* ret);
@@ -463,8 +473,13 @@ UINT32 smartcard_pack_reconnect_return(SMARTCARD_DEVICE* smartcard, wStream* s,
 UINT32 smartcard_unpack_hcard_and_disposition_call(SMARTCARD_DEVICE* smartcard, wStream* s, HCardAndDisposition_Call* call);
 
 UINT32 smartcard_unpack_get_status_change_a_call(SMARTCARD_DEVICE* smartcard, wStream* s, GetStatusChangeA_Call* call);
+void smartcard_trace_get_status_change_a_call(SMARTCARD_DEVICE* smartcard, GetStatusChangeA_Call* call);
+
 UINT32 smartcard_unpack_get_status_change_w_call(SMARTCARD_DEVICE* smartcard, wStream* s, GetStatusChangeW_Call* call);
+void smartcard_trace_get_status_change_w_call(SMARTCARD_DEVICE* smartcard, GetStatusChangeW_Call* call);
+
 UINT32 smartcard_pack_get_status_change_return(SMARTCARD_DEVICE* smartcard, wStream* s, GetStatusChange_Return* ret);
+void smartcard_trace_get_status_change_return(SMARTCARD_DEVICE* smartcard, GetStatusChange_Return* ret);
 
 UINT32 smartcard_unpack_state_call(SMARTCARD_DEVICE* smartcard, wStream* s, State_Call* call);
 UINT32 smartcard_pack_state_return(SMARTCARD_DEVICE* smartcard, wStream* s, State_Return* ret);

diff --git a/winpr/include/winpr/wlog.h b/winpr/include/winpr/wlog.h
index eda5e60..b2c1c97 100644 (file)
--- a/winpr/include/winpr/wlog.h
+++ b/winpr/include/winpr/wlog.h
@@ -246,6 +246,9 @@ WINPR_API void WLog_PrintMessage(wLog* log, wLogMessage* message, ...);
                WLog_PrintMessage(_log, &(_log_message), ## __VA_ARGS__ ); \
        }
 
+#define WLog_IsLevelActive(_log, _log_level) \
+       (_log_level >= WLog_GetLogLevel(_log))
+
 WINPR_API DWORD WLog_GetLogLevel(wLog* log);
 WINPR_API void WLog_SetLogLevel(wLog* log, DWORD logLevel);