rail: added verbose logs (#5402)
authorDavid Fort <contact@hardening-consulting.com>
Thu, 23 May 2019 10:15:26 +0000 (12:15 +0200)
committerakallabeth <akallabeth@users.noreply.github.com>
Thu, 23 May 2019 10:15:26 +0000 (12:15 +0200)
* rail: added verbose logs

* rail: fix buffer initialisation in debug message

channels/rail/client/rail_orders.c
libfreerdp/core/update.c
libfreerdp/core/window.c

index 98834e6..da92707 100644 (file)
@@ -153,8 +153,7 @@ static UINT rail_read_server_exec_result_order(wStream* s, RAIL_EXEC_RESULT_ORDE
        Stream_Read_UINT16(s, execResult->execResult); /* execResult (2 bytes) */
        Stream_Read_UINT32(s, execResult->rawResult); /* rawResult (4 bytes) */
        Stream_Seek_UINT16(s); /* padding (2 bytes) */
-       return rail_read_unicode_string(s,
-                                       &execResult->exeOrFile) ? CHANNEL_RC_OK : ERROR_INTERNAL_ERROR; /* exeOrFile */
+       return rail_read_unicode_string(s, &execResult->exeOrFile) ? CHANNEL_RC_OK : ERROR_INTERNAL_ERROR; /* exeOrFile */
 }
 
 /**
@@ -269,8 +268,7 @@ static UINT rail_read_server_get_appid_resp_order(wStream* s,
        }
 
        Stream_Read_UINT32(s, getAppidResp->windowId); /* windowId (4 bytes) */
-       Stream_Read(s, (BYTE*) & (getAppidResp->applicationId),
-                   512); /* applicationId (256 UNICODE chars) */
+       Stream_Read(s, (BYTE*) & (getAppidResp->applicationId), 512); /* applicationId (256 UNICODE chars) */
        return CHANNEL_RC_OK;
 }
 
index bcf2d51..9d904c6 100644 (file)
@@ -174,13 +174,10 @@ static BOOL update_write_bitmap_data(rdpUpdate* update, wStream* s,
        {
                if (!(bitmapData->flags & NO_BITMAP_COMPRESSION_HDR))
                {
-                       Stream_Write_UINT16(s,
-                                           bitmapData->cbCompFirstRowSize); /* cbCompFirstRowSize (2 bytes) */
-                       Stream_Write_UINT16(s,
-                                           bitmapData->cbCompMainBodySize); /* cbCompMainBodySize (2 bytes) */
+                       Stream_Write_UINT16(s, bitmapData->cbCompFirstRowSize); /* cbCompFirstRowSize (2 bytes) */
+                       Stream_Write_UINT16(s, bitmapData->cbCompMainBodySize); /* cbCompMainBodySize (2 bytes) */
                        Stream_Write_UINT16(s, bitmapData->cbScanWidth); /* cbScanWidth (2 bytes) */
-                       Stream_Write_UINT16(s,
-                                           bitmapData->cbUncompressedSize); /* cbUncompressedSize (2 bytes) */
+                       Stream_Write_UINT16(s, bitmapData->cbUncompressedSize); /* cbUncompressedSize (2 bytes) */
                }
 
                Stream_Write(s, bitmapData->bitmapDataStream, bitmapData->bitmapLength);
@@ -387,10 +384,8 @@ static BOOL _update_read_pointer_color(wStream* s, POINTER_COLOR_UPDATE* pointer
        if ((pointer_color->width > 96) || (pointer_color->height > 96))
                goto fail;
 
-       Stream_Read_UINT16(s,
-                          pointer_color->lengthAndMask); /* lengthAndMask (2 bytes) */
-       Stream_Read_UINT16(s,
-                          pointer_color->lengthXorMask); /* lengthXorMask (2 bytes) */
+       Stream_Read_UINT16(s, pointer_color->lengthAndMask); /* lengthAndMask (2 bytes) */
+       Stream_Read_UINT16(s, pointer_color->lengthXorMask); /* lengthXorMask (2 bytes) */
 
        /**
         * There does not seem to be any documentation on why
@@ -458,7 +453,7 @@ static BOOL _update_read_pointer_color(wStream* s, POINTER_COLOR_UPDATE* pointer
 
                if (scanlineSize * pointer_color->height != pointer_color->lengthAndMask)
                {
-                       WLog_ERR(TAG,  "invalid lengthAndMask: %"PRIu32" instead of %"PRIu32"",
+                       WLog_ERR(TAG, "invalid lengthAndMask: %"PRIu32" instead of %"PRIu32"",
                                 pointer_color->lengthAndMask, scanlineSize * pointer_color->height);
                        goto fail;
                }
@@ -510,7 +505,7 @@ POINTER_NEW_UPDATE* update_read_pointer_new(rdpUpdate* update, wStream* s)
 
        if ((pointer_new->xorBpp < 1) || (pointer_new->xorBpp > 32))
        {
-               WLog_ERR(TAG,  "invalid xorBpp %"PRIu32"", pointer_new->xorBpp);
+               WLog_ERR(TAG, "invalid xorBpp %"PRIu32"", pointer_new->xorBpp);
                goto fail;
        }
 
@@ -810,9 +805,8 @@ static BOOL _update_end_paint(rdpContext* context)
 
        if (update->numberOrders > 0)
        {
-               WLog_DBG(TAG,  "sending %"PRIu16" orders", update->numberOrders);
-               fastpath_send_update_pdu(context->rdp->fastpath, FASTPATH_UPDATETYPE_ORDERS, s,
-                                        FALSE);
+               WLog_DBG(TAG, "sending %"PRIu16" orders", update->numberOrders);
+               fastpath_send_update_pdu(context->rdp->fastpath, FASTPATH_UPDATETYPE_ORDERS, s, FALSE);
        }
 
        update->combineUpdates = FALSE;
@@ -1011,8 +1005,7 @@ static BOOL update_send_refresh_rect(rdpContext* context, BYTE count,
        return TRUE;
 }
 
-static void update_write_suppress_output(wStream* s, BYTE allow,
-        const RECTANGLE_16* area)
+static void update_write_suppress_output(wStream* s, BYTE allow, const RECTANGLE_16* area)
 {
        Stream_Write_UINT8(s, allow); /* allowDisplayUpdates (1 byte) */
        /* Use zeros for padding (like mstsc) for compatibility with legacy servers */
@@ -1247,6 +1240,7 @@ static BOOL update_send_play_sound(rdpContext* context,
        Stream_Write_UINT32(s, play_sound->frequency);
        return rdp_send_data_pdu(rdp, s, DATA_PDU_TYPE_PLAY_SOUND, rdp->mcs->userId);
 }
+
 /**
  * Primary Drawing Orders
  */
@@ -1260,8 +1254,7 @@ static BOOL update_send_dstblt(rdpContext* context,
        ORDER_INFO orderInfo;
        int inf;
        rdpUpdate* update = context->update;
-       headerLength = update_prepare_order_info(context, &orderInfo,
-                      ORDER_TYPE_DSTBLT);
+       headerLength = update_prepare_order_info(context, &orderInfo, ORDER_TYPE_DSTBLT);
        inf = update_approximate_dstblt_order(&orderInfo, dstblt);
        update_check_flush(context, headerLength + inf);
        s = update->us;
@@ -1500,8 +1493,7 @@ static BOOL update_send_cache_bitmap(rdpContext* context,
        em = Stream_GetPosition(s);
        orderLength = (em - bm) - 13;
        Stream_SetPosition(s, bm);
-       Stream_Write_UINT8(s, ORDER_STANDARD |
-                          ORDER_SECONDARY); /* controlFlags (1 byte) */
+       Stream_Write_UINT8(s, ORDER_STANDARD | ORDER_SECONDARY); /* controlFlags (1 byte) */
        Stream_Write_UINT16(s, orderLength); /* orderLength (2 bytes) */
        Stream_Write_UINT16(s, extraFlags); /* extraFlags (2 bytes) */
        Stream_Write_UINT8(s, orderType); /* orderType (1 byte) */
index fa9ee3c..9e555ac 100644 (file)
@@ -461,8 +461,7 @@ static BOOL update_read_window_cached_icon_order(wStream* s, WINDOW_ORDER_INFO*
         WINDOW_CACHED_ICON_ORDER* window_cached_icon)
 {
        WINPR_UNUSED(orderInfo);
-       return update_read_cached_icon_info(s,
-                                           &window_cached_icon->cachedIcon); /* cachedIcon (CACHED_ICON_INFO) */
+       return update_read_cached_icon_info(s, &window_cached_icon->cachedIcon); /* cachedIcon (CACHED_ICON_INFO) */
 }
 
 static void update_read_window_delete_order(wStream* s, WINDOW_ORDER_INFO* orderInfo)
@@ -498,6 +497,148 @@ static BOOL window_order_supported(const rdpSettings* settings, UINT32 fieldFlag
        }
 }
 
+
+#define DUMP_APPEND(...) do { \
+               _snprintf(tmpBuffer, sizeof(tmpBuffer), __VA_ARGS__); \
+               strncat(buffer, tmpBuffer, rem); \
+               rem -= strlen(tmpBuffer); \
+               } while(0)
+
+
+static void dump_window_state_order(wLog *log, const char *msg, const WINDOW_ORDER_INFO* order, const WINDOW_STATE_ORDER *state)
+{
+       char buffer[3000];
+       char tmpBuffer[100];
+       size_t rem = sizeof(buffer) - 1;
+
+       _snprintf(buffer, sizeof(buffer), "%s windowId=0x%"PRIu32"", msg, order->windowId);
+       rem -= strlen(msg);
+
+       if (order->fieldFlags & WINDOW_ORDER_FIELD_OWNER)
+               DUMP_APPEND(" owner=0x%"PRIx32"", state->ownerWindowId);
+       if (order->fieldFlags & WINDOW_ORDER_FIELD_STYLE)
+       {
+               DUMP_APPEND(" [ex]style=<0x%"PRIx32", 0x%"PRIx32"", state->style, state->extendedStyle);
+               if (state->style & WS_POPUP)
+                       DUMP_APPEND(" popup");
+               if (state->style & WS_VISIBLE)
+                       DUMP_APPEND(" visible");
+               if (state->style & WS_THICKFRAME)
+                       DUMP_APPEND(" thickframe");
+               if (state->style & WS_BORDER)
+                       DUMP_APPEND(" border");
+               if (state->style & WS_CAPTION)
+                       DUMP_APPEND(" caption");
+
+               if (state->extendedStyle & WS_EX_NOACTIVATE)
+                       DUMP_APPEND(" noactivate");
+               if (state->extendedStyle & WS_EX_TOOLWINDOW)
+                       DUMP_APPEND(" toolWindow");
+               if (state->extendedStyle & WS_EX_TOPMOST)
+                       DUMP_APPEND(" topMost");
+
+               DUMP_APPEND(">");
+       }
+
+       if (order->fieldFlags & WINDOW_ORDER_FIELD_SHOW)
+       {
+               const char *showStr;
+               switch(state->showState)
+               {
+               case 0: showStr = "hidden"; break;
+               case 2: showStr = "minimized"; break;
+               case 3: showStr = "maximized"; break;
+               case 5: showStr = "current"; break;
+               default: showStr = "<unknown>"; break;
+               }
+               DUMP_APPEND(" show=%s", showStr);
+       }
+
+       if (order->fieldFlags & WINDOW_ORDER_FIELD_TITLE)
+               DUMP_APPEND(" title");
+       if (order->fieldFlags & WINDOW_ORDER_FIELD_CLIENT_AREA_OFFSET)
+               DUMP_APPEND(" clientOffsetX=%"PRId32" clientOffsetY=%"PRId32"",
+                               state->clientOffsetX, state->clientOffsetY);
+       if (order->fieldFlags & WINDOW_ORDER_FIELD_CLIENT_AREA_SIZE)
+               DUMP_APPEND(" clientAreaWidth=%"PRIu32" clientAreaHeight=%"PRIu32"",
+                               state->clientAreaWidth, state->clientAreaHeight);
+       if (order->fieldFlags & WINDOW_ORDER_FIELD_RESIZE_MARGIN_X)
+               DUMP_APPEND(" resizeMarginLeft=%"PRIu32" resizeMarginRight=%"PRIu32"",
+                               state->resizeMarginLeft, state->resizeMarginRight);
+       if (order->fieldFlags & WINDOW_ORDER_FIELD_RESIZE_MARGIN_Y)
+               DUMP_APPEND(" resizeMarginTop=%"PRIu32" resizeMarginBottom=%"PRIu32"",
+                               state->resizeMarginTop, state->resizeMarginBottom);
+       if (order->fieldFlags & WINDOW_ORDER_FIELD_RP_CONTENT)
+               DUMP_APPEND(" rpContent=0x%"PRIx8"", state->RPContent);
+       if (order->fieldFlags & WINDOW_ORDER_FIELD_ROOT_PARENT)
+               DUMP_APPEND(" rootParent=0x%"PRIx32"", state->rootParentHandle);
+       if (order->fieldFlags & WINDOW_ORDER_FIELD_WND_OFFSET)
+               DUMP_APPEND(" windowOffsetX=%"PRId32" windowOffsetY=%"PRId32"", state->windowOffsetX, state->windowOffsetY);
+       if (order->fieldFlags & WINDOW_ORDER_FIELD_WND_CLIENT_DELTA)
+               DUMP_APPEND(" windowClientDeltaX=%"PRId32" windowClientDeltaY=%"PRId32"",
+                               state->windowClientDeltaX, state->windowClientDeltaY);
+       if (order->fieldFlags & WINDOW_ORDER_FIELD_WND_SIZE)
+               DUMP_APPEND(" windowWidth=%"PRIu32" windowHeight=%"PRIu32"", state->windowWidth, state->windowHeight);
+
+       if (order->fieldFlags & WINDOW_ORDER_FIELD_WND_RECTS)
+       {
+               UINT32 i;
+               DUMP_APPEND(" windowRects=(");
+               for(i = 0; i < state->numWindowRects; i++)
+               {
+                       DUMP_APPEND("(%"PRIu16",%"PRIu16",%"PRIu16",%"PRIu16")",
+                                       state->windowRects[i].left, state->windowRects[i].top,
+                                       state->windowRects[i].right, state->windowRects[i].bottom);
+               }
+               DUMP_APPEND(")");
+       }
+
+       if (order->fieldFlags & WINDOW_ORDER_FIELD_VIS_OFFSET)
+               DUMP_APPEND(" visibleOffsetX=%"PRId32" visibleOffsetY=%"PRId32"", state->visibleOffsetX, state->visibleOffsetY);
+
+       if (order->fieldFlags & WINDOW_ORDER_FIELD_VISIBILITY)
+       {
+               UINT32 i;
+               DUMP_APPEND(" visibilityRects=(");
+               for(i = 0; i < state->numVisibilityRects; i++)
+               {
+                       DUMP_APPEND("(%"PRIu16",%"PRIu16",%"PRIu16",%"PRIu16")",
+                                       state->visibilityRects[i].left, state->visibilityRects[i].top,
+                                       state->visibilityRects[i].right, state->visibilityRects[i].bottom);
+               }
+               DUMP_APPEND(")");
+       }
+
+       if (order->fieldFlags & WINDOW_ORDER_FIELD_OVERLAY_DESCRIPTION)
+               DUMP_APPEND(" overlayDescr");
+
+       if (order->fieldFlags & WINDOW_ORDER_FIELD_ICON_OVERLAY_NULL)
+               DUMP_APPEND(" iconOverlayNull");
+
+       if (order->fieldFlags & WINDOW_ORDER_FIELD_TASKBAR_BUTTON)
+               DUMP_APPEND(" taskBarButton=0x%"PRIx8"", state->TaskbarButton);
+
+       if (order->fieldFlags & WINDOW_ORDER_FIELD_ENFORCE_SERVER_ZORDER)
+               DUMP_APPEND(" enforceServerZOrder=0x%"PRIx8"", state->EnforceServerZOrder);
+       if (order->fieldFlags & WINDOW_ORDER_FIELD_APPBAR_STATE)
+               DUMP_APPEND(" appBarState=0x%"PRIx8"", state->AppBarState);
+       if (order->fieldFlags & WINDOW_ORDER_FIELD_APPBAR_EDGE)
+       {
+               const char *appBarEdgeStr;
+               switch (state->AppBarEdge)
+               {
+               case 0: appBarEdgeStr = "left"; break;
+               case 1: appBarEdgeStr = "top"; break;
+               case 2: appBarEdgeStr = "right"; break;
+               case 3: appBarEdgeStr = "bottom"; break;
+               default: appBarEdgeStr = "<unknown>"; break;
+               }
+               DUMP_APPEND(" appBarEdge=%s", appBarEdgeStr);
+       }
+
+       WLog_Print(log, WLOG_DEBUG, buffer);
+}
+
 static BOOL update_recv_window_info_order(rdpUpdate* update, wStream* s,
         WINDOW_ORDER_INFO* orderInfo)
 {
@@ -517,7 +658,7 @@ static BOOL update_recv_window_info_order(rdpUpdate* update, wStream* s,
 
                if (result)
                {
-                       WLog_Print(update->log, WLOG_DEBUG, "WindowIcon");
+                       WLog_Print(update->log, WLOG_DEBUG, "WindowIcon windowId=0x%"PRIx32"", orderInfo->windowId);
                        IFCALLRET(window->WindowIcon, result, context, orderInfo, &window_icon);
                }
 
@@ -531,14 +672,14 @@ static BOOL update_recv_window_info_order(rdpUpdate* update, wStream* s,
 
                if (result)
                {
-                       WLog_Print(update->log, WLOG_DEBUG, "WindowCachedIcon");
+                       WLog_Print(update->log, WLOG_DEBUG, "WindowCachedIcon windowId=0x%"PRIx32"", orderInfo->windowId);
                        IFCALLRET(window->WindowCachedIcon, result, context, orderInfo, &window_cached_icon);
                }
        }
        else if (orderInfo->fieldFlags & WINDOW_ORDER_STATE_DELETED)
        {
                update_read_window_delete_order(s, orderInfo);
-               WLog_Print(update->log, WLOG_DEBUG, "WindowDelete");
+               WLog_Print(update->log, WLOG_DEBUG, "WindowDelete windowId=0x%"PRIx32"", orderInfo->windowId);
                IFCALLRET(window->WindowDelete, result, context, orderInfo);
        }
        else
@@ -550,12 +691,12 @@ static BOOL update_recv_window_info_order(rdpUpdate* update, wStream* s,
                {
                        if (orderInfo->fieldFlags & WINDOW_ORDER_STATE_NEW)
                        {
-                               WLog_Print(update->log, WLOG_DEBUG, "WindowCreate");
+                               dump_window_state_order(update->log, "WindowCreate", orderInfo, &windowState);
                                IFCALLRET(window->WindowCreate, result, context, orderInfo, &windowState);
                        }
                        else
                        {
-                               WLog_Print(update->log, WLOG_DEBUG, "WindowUpdate");
+                               dump_window_state_order(update->log, "WindowUpdate", orderInfo, &windowState);
                                IFCALLRET(window->WindowUpdate, result, context, orderInfo, &windowState);
                        }
 
@@ -594,8 +735,7 @@ static BOOL update_read_notification_icon_state_order(wStream* s, WINDOW_ORDER_I
 
        if (orderInfo->fieldFlags & WINDOW_ORDER_FIELD_NOTIFY_INFO_TIP)
        {
-               if (!update_read_notify_icon_infotip(s,
-                                                    &notify_icon_state->infoTip)) /* infoTip (NOTIFY_ICON_INFOTIP) */
+               if (!update_read_notify_icon_infotip(s, &notify_icon_state->infoTip)) /* infoTip (NOTIFY_ICON_INFOTIP) */
                        return FALSE;
        }
 
@@ -615,8 +755,7 @@ static BOOL update_read_notification_icon_state_order(wStream* s, WINDOW_ORDER_I
 
        if (orderInfo->fieldFlags & WINDOW_ORDER_CACHED_ICON)
        {
-               if (!update_read_cached_icon_info(s,
-                                                 &notify_icon_state->cachedIcon)) /* cachedIcon (CACHED_ICON_INFO) */
+               if (!update_read_cached_icon_info(s, &notify_icon_state->cachedIcon)) /* cachedIcon (CACHED_ICON_INFO) */
                        return FALSE;
        }
 
@@ -728,6 +867,32 @@ static void update_read_desktop_non_monitored_order(wStream* s, WINDOW_ORDER_INF
        /* non-monitored desktop notification event */
 }
 
+static void dump_monitored_desktop(wLog *log, const char *msg, const WINDOW_ORDER_INFO* orderInfo,
+               const MONITORED_DESKTOP_ORDER *monitored)
+{
+       char buffer[1000] = {0};
+       char tmpBuffer[1000];
+       size_t rem = sizeof(buffer) - 1;
+
+       DUMP_APPEND(msg);
+
+       if (orderInfo->fieldFlags & WINDOW_ORDER_FIELD_DESKTOP_ACTIVE_WND)
+               DUMP_APPEND(" activeWindowId=0x%"PRIx32"", monitored->activeWindowId);
+
+       if (orderInfo->fieldFlags & WINDOW_ORDER_FIELD_DESKTOP_ZORDER)
+       {
+               UINT32 i;
+
+               DUMP_APPEND(" windows=(");
+               for (i = 0; i < monitored->numWindowIds; i++)
+               {
+                       DUMP_APPEND("0x%"PRIx32",", monitored->windowIds[i]);
+               }
+               DUMP_APPEND(")");
+       }
+       WLog_Print(log, WLOG_DEBUG, buffer);
+}
+
 static BOOL update_recv_desktop_info_order(rdpUpdate* update, wStream* s,
         WINDOW_ORDER_INFO* orderInfo)
 {
@@ -738,7 +903,7 @@ static BOOL update_recv_desktop_info_order(rdpUpdate* update, wStream* s,
        if (orderInfo->fieldFlags & WINDOW_ORDER_FIELD_DESKTOP_NONE)
        {
                update_read_desktop_non_monitored_order(s, orderInfo);
-               WLog_Print(update->log, WLOG_DEBUG, "NonMonitoredDesktop");
+               WLog_Print(update->log, WLOG_DEBUG, "NonMonitoredDesktop, windowId=0x%"PRIx32"", orderInfo->windowId);
                IFCALLRET(window->NonMonitoredDesktop, result, context, orderInfo);
        }
        else
@@ -748,7 +913,7 @@ static BOOL update_recv_desktop_info_order(rdpUpdate* update, wStream* s,
 
                if (result)
                {
-                       WLog_Print(update->log, WLOG_DEBUG, "ActivelyMonitoredDesktop");
+                       dump_monitored_desktop(update->log, "ActivelyMonitoredDesktop", orderInfo, &monitored_desktop);
                        IFCALLRET(window->MonitoredDesktop, result, context, orderInfo, &monitored_desktop);
                }