TDE
/
libtdevnc
mirror of https://mirror.git.trinitydesktop.org/gitea/TDE/libtdevnc
0
0
Fork 0
Code Issues Releases Wiki Activity

websockets: hide decode debug output per default

Browse Source
pull/3/head
Christian Beier 8 years ago
parent 0e76b289c8
commit 051fe2a009
No known key found for this signature in database
GPG Key ID: 421BB3B45C6067F8
1 changed files with 41 additions and 32 deletions
Show Stats Download Patch File Download Diff File

73
libvncserver/ws_decode.c
Unescape View File

@ -8,6 +8,17 @@
#define WS_HYBI_HEADER_LEN_EXTENDED 4 + WS_HYBI_MASK_LEN #define WS_HYBI_HEADER_LEN_EXTENDED 4 + WS_HYBI_MASK_LEN
#define WS_HYBI_HEADER_LEN_LONG 10 + WS_HYBI_MASK_LEN #define WS_HYBI_HEADER_LEN_LONG 10 + WS_HYBI_MASK_LEN
#undef WS_DECODE_DEBUG
/* set to 1 to produce very fine debugging output */
#define WS_DECODE_DEBUG 0
#if WS_DECODE_DEBUG == 1
#define ws_dbg(fmt, ...) rfbLog((fmt), ##__VA_ARGS)
#else
#define ws_dbg(fmt, ...)
#endif
static inline int static inline int
isControlFrame(ws_ctx_t *wsctx) isControlFrame(ws_ctx_t *wsctx)
{ {
@ -42,7 +53,7 @@ static void
hybiDecodeCleanupForContinuation(ws_ctx_t *wsctx) hybiDecodeCleanupForContinuation(ws_ctx_t *wsctx)
{ {
hybiDecodeCleanupBasics(wsctx); hybiDecodeCleanupBasics(wsctx);
rfbLog("clean up frame, but expect continuation with opcode %d\n", wsctx->continuation_opcode); ws_dbg("clean up frame, but expect continuation with opcode %d\n", wsctx->continuation_opcode);
} }
void void
@ -50,7 +61,7 @@ hybiDecodeCleanupComplete(ws_ctx_t *wsctx)
{ {
hybiDecodeCleanupBasics(wsctx); hybiDecodeCleanupBasics(wsctx);
wsctx->continuation_opcode = WS_OPCODE_INVALID; wsctx->continuation_opcode = WS_OPCODE_INVALID;
rfbLog("cleaned up wsctx completely\n"); ws_dbg("cleaned up wsctx completely\n");
} }
@ -73,14 +84,14 @@ hybiReturnData(char *dst, int len, ws_ctx_t *wsctx, int *nWritten)
if (wsctx->readlen > 0) { if (wsctx->readlen > 0) {
/* simply return what we have */ /* simply return what we have */
if (wsctx->readlen > len) { if (wsctx->readlen > len) {
rfbLog("copy to %d bytes to dst buffer; readPos=%p, readLen=%d\n", len, wsctx->readPos, wsctx->readlen); ws_dbg("copy to %d bytes to dst buffer; readPos=%p, readLen=%d\n", len, wsctx->readPos, wsctx->readlen);
memcpy(dst, wsctx->readPos, len); memcpy(dst, wsctx->readPos, len);
*nWritten = len; *nWritten = len;
wsctx->readlen -= len; wsctx->readlen -= len;
wsctx->readPos += len; wsctx->readPos += len;
nextState = WS_HYBI_STATE_DATA_AVAILABLE; nextState = WS_HYBI_STATE_DATA_AVAILABLE;
} else { } else {
rfbLog("copy to %d bytes to dst buffer; readPos=%p, readLen=%d\n", wsctx->readlen, wsctx->readPos, wsctx->readlen); ws_dbg("copy to %d bytes to dst buffer; readPos=%p, readLen=%d\n", wsctx->readlen, wsctx->readPos, wsctx->readlen);
memcpy(dst, wsctx->readPos, wsctx->readlen); memcpy(dst, wsctx->readPos, wsctx->readlen);
*nWritten = wsctx->readlen; *nWritten = wsctx->readlen;
wsctx->readlen = 0; wsctx->readlen = 0;
@ -91,7 +102,7 @@ hybiReturnData(char *dst, int len, ws_ctx_t *wsctx, int *nWritten)
nextState = WS_HYBI_STATE_DATA_NEEDED; nextState = WS_HYBI_STATE_DATA_NEEDED;
} }
} }
rfbLog("after copy: readPos=%p, readLen=%d\n", wsctx->readPos, wsctx->readlen); ws_dbg("after copy: readPos=%p, readLen=%d\n", wsctx->readPos, wsctx->readlen);
} else { } else {
/* it may happen that we read some bytes but could not decode them, /* it may happen that we read some bytes but could not decode them,
* in that case, set errno to EAGAIN and return -1 */ * in that case, set errno to EAGAIN and return -1 */
@ -122,9 +133,9 @@ hybiReadHeader(ws_ctx_t *wsctx, int *sockRet, int *nPayload)
int n = ((uint64_t)WSHLENMAX) - wsctx->header.nRead; int n = ((uint64_t)WSHLENMAX) - wsctx->header.nRead;
rfbLog("header_read to %p with len=%d\n", headerDst, n); ws_dbg("header_read to %p with len=%d\n", headerDst, n);
ret = wsctx->ctxInfo.readFunc(wsctx->ctxInfo.ctxPtr, headerDst, n); ret = wsctx->ctxInfo.readFunc(wsctx->ctxInfo.ctxPtr, headerDst, n);
rfbLog("read %d bytes from socket\n", ret); ws_dbg("read %d bytes from socket\n", ret);
if (ret <= 0) { if (ret <= 0) {
if (-1 == ret) { if (-1 == ret) {
/* save errno because rfbErr() will tamper it */ /* save errno because rfbErr() will tamper it */
@ -150,7 +161,7 @@ hybiReadHeader(ws_ctx_t *wsctx, int *sockRet, int *nPayload)
wsctx->header.opcode = wsctx->header.data->b0 & 0x0f; wsctx->header.opcode = wsctx->header.data->b0 & 0x0f;
wsctx->header.fin = (wsctx->header.data->b0 & 0x80) >> 7; wsctx->header.fin = (wsctx->header.data->b0 & 0x80) >> 7;
if (isControlFrame(wsctx)) { if (isControlFrame(wsctx)) {
rfbLog("is control frame\n"); ws_dbg("is control frame\n");
/* is a control frame, leave remembered continuation opcode unchanged; /* is a control frame, leave remembered continuation opcode unchanged;
* just check if there is a wrong fragmentation */ * just check if there is a wrong fragmentation */
if (wsctx->header.fin == 0) { if (wsctx->header.fin == 0) {
@ -164,10 +175,10 @@ hybiReadHeader(ws_ctx_t *wsctx, int *sockRet, int *nPayload)
goto err_cleanup_state; goto err_cleanup_state;
} }
} else { } else {
rfbLog("not a control frame\n"); ws_dbg("not a control frame\n");
/* not a control frame, check for continuation opcode */ /* not a control frame, check for continuation opcode */
if (wsctx->header.opcode == WS_OPCODE_CONTINUATION) { if (wsctx->header.opcode == WS_OPCODE_CONTINUATION) {
rfbLog("cont_frame\n"); ws_dbg("cont_frame\n");
/* do we have state (i.e., opcode) for continuation frame? */ /* do we have state (i.e., opcode) for continuation frame? */
if (wsctx->continuation_opcode == WS_OPCODE_INVALID) { if (wsctx->continuation_opcode == WS_OPCODE_INVALID) {
rfbErr("no continuation state\n"); rfbErr("no continuation state\n");
@ -177,19 +188,19 @@ hybiReadHeader(ws_ctx_t *wsctx, int *sockRet, int *nPayload)
/* otherwise, set opcode = continuation_opcode */ /* otherwise, set opcode = continuation_opcode */
wsctx->header.opcode = wsctx->continuation_opcode; wsctx->header.opcode = wsctx->continuation_opcode;
rfbLog("set opcode to continuation_opcode: %d\n", wsctx->header.opcode); ws_dbg("set opcode to continuation_opcode: %d\n", wsctx->header.opcode);
} else { } else {
if (wsctx->header.fin == 0) { if (wsctx->header.fin == 0) {
wsctx->continuation_opcode = wsctx->header.opcode; wsctx->continuation_opcode = wsctx->header.opcode;
} else { } else {
wsctx->continuation_opcode = WS_OPCODE_INVALID; wsctx->continuation_opcode = WS_OPCODE_INVALID;
} }
rfbLog("set continuation_opcode to %d\n", wsctx->continuation_opcode); ws_dbg("set continuation_opcode to %d\n", wsctx->continuation_opcode);
} }
} }
wsctx->header.payloadLen = (uint64_t)(wsctx->header.data->b1 & 0x7f); wsctx->header.payloadLen = (uint64_t)(wsctx->header.data->b1 & 0x7f);
rfbLog("first header bytes received; opcode=%d lenbyte=%d fin=%d\n", wsctx->header.opcode, wsctx->header.payloadLen, wsctx->header.fin); ws_dbg("first header bytes received; opcode=%d lenbyte=%d fin=%d\n", wsctx->header.opcode, wsctx->header.payloadLen, wsctx->header.fin);
/* /*
* 4.3. Client-to-Server Masking * 4.3. Client-to-Server Masking
@ -223,11 +234,11 @@ hybiReadHeader(ws_ctx_t *wsctx, int *sockRet, int *nPayload)
char *h = wsctx->codeBufDecode; char *h = wsctx->codeBufDecode;
int i; int i;
rfbLog("Header:\n"); ws_dbg("Header:\n");
for (i=0; i <10; i++) { for (i=0; i <10; i++) {
rfbLog("0x%02X\n", (unsigned char)h[i]); ws_dbg("0x%02X\n", (unsigned char)h[i]);
} }
rfbLog("\n"); ws_dbg("\n");
/* while RFC 6455 mandates that lengths MUST be encoded with the minimum /* while RFC 6455 mandates that lengths MUST be encoded with the minimum
* number of bytes, it does not specify for the server how to react on * number of bytes, it does not specify for the server how to react on
@ -250,7 +261,7 @@ hybiReadHeader(ws_ctx_t *wsctx, int *sockRet, int *nPayload)
*nPayload = wsctx->header.nRead - wsctx->header.headerLen; *nPayload = wsctx->header.nRead - wsctx->header.headerLen;
wsctx->nReadPayload = *nPayload; wsctx->nReadPayload = *nPayload;
rfbLog("header complete: state=%d headerlen=%d payloadlen=%llu writeTo=%p nPayload=%d\n", wsctx->hybiDecodeState, wsctx->header.headerLen, wsctx->header.payloadLen, wsctx->writePos, *nPayload); ws_dbg("header complete: state=%d headerlen=%d payloadlen=%llu writeTo=%p nPayload=%d\n", wsctx->hybiDecodeState, wsctx->header.headerLen, wsctx->header.payloadLen, wsctx->writePos, *nPayload);
return WS_HYBI_STATE_DATA_NEEDED; return WS_HYBI_STATE_DATA_NEEDED;
@ -323,14 +334,14 @@ hybiReadAndDecode(ws_ctx_t *wsctx, char *dst, int len, int *sockRet, int nInBuf)
/* -1 accounts for potential '\0' terminator for base64 decoding */ /* -1 accounts for potential '\0' terminator for base64 decoding */
bufsize = wsctx->codeBufDecode + ARRAYSIZE(wsctx->codeBufDecode) - wsctx->writePos - 1; bufsize = wsctx->codeBufDecode + ARRAYSIZE(wsctx->codeBufDecode) - wsctx->writePos - 1;
rfbLog("bufsize=%d\n", bufsize); ws_dbg("bufsize=%d\n", bufsize);
if (hybiRemaining(wsctx) > bufsize) { if (hybiRemaining(wsctx) > bufsize) {
nextRead = bufsize; nextRead = bufsize;
} else { } else {
nextRead = hybiRemaining(wsctx); nextRead = hybiRemaining(wsctx);
} }
rfbLog("calling read with buf=%p and len=%d (decodebuf=%p headerLen=%d)\n", wsctx->writePos, nextRead, wsctx->codeBufDecode, wsctx->header.headerLen); ws_dbg("calling read with buf=%p and len=%d (decodebuf=%p headerLen=%d)\n", wsctx->writePos, nextRead, wsctx->codeBufDecode, wsctx->header.headerLen);
if (nextRead > 0) { if (nextRead > 0) {
/* decode more data */ /* decode more data */
@ -344,7 +355,7 @@ hybiReadAndDecode(ws_ctx_t *wsctx, char *dst, int len, int *sockRet, int nInBuf)
*sockRet = 0; *sockRet = 0;
return WS_HYBI_STATE_ERR; return WS_HYBI_STATE_ERR;
} else { } else {
rfbLog("read %d bytes from socket; nRead=%d\n", n, wsctx->nReadPayload); ws_dbg("read %d bytes from socket; nRead=%d\n", n, wsctx->nReadPayload);
} }
} else { } else {
n = 0; n = 0;
@ -360,7 +371,7 @@ hybiReadAndDecode(ws_ctx_t *wsctx, char *dst, int len, int *sockRet, int nInBuf)
/* number of not yet unmasked payload bytes: what we read here + what was /* number of not yet unmasked payload bytes: what we read here + what was
* carried over + what was read with the header */ * carried over + what was read with the header */
toDecode = n + wsctx->carrylen + nInBuf; toDecode = n + wsctx->carrylen + nInBuf;
rfbLog("toDecode=%d from n=%d carrylen=%d headerLen=%d\n", toDecode, n, wsctx->carrylen, wsctx->header.headerLen); ws_dbg("toDecode=%d from n=%d carrylen=%d headerLen=%d\n", toDecode, n, wsctx->carrylen, wsctx->header.headerLen);
if (toDecode < 0) { if (toDecode < 0) {
rfbErr("%s: internal error; negative number of bytes to decode: %d", __func__, toDecode); rfbErr("%s: internal error; negative number of bytes to decode: %d", __func__, toDecode);
errno=EIO; errno=EIO;
@ -376,7 +387,7 @@ hybiReadAndDecode(ws_ctx_t *wsctx, char *dst, int len, int *sockRet, int nInBuf)
for (i = 0; i < (toDecode >> 2); i++) { for (i = 0; i < (toDecode >> 2); i++) {
data32[i] ^= wsctx->header.mask.u; data32[i] ^= wsctx->header.mask.u;
} }
rfbLog("mask decoding; i=%d toDecode=%d\n", i, toDecode); ws_dbg("mask decoding; i=%d toDecode=%d\n", i, toDecode);
if (wsctx->hybiDecodeState == WS_HYBI_STATE_FRAME_COMPLETE) { if (wsctx->hybiDecodeState == WS_HYBI_STATE_FRAME_COMPLETE) {
/* process the remaining bytes (if any) */ /* process the remaining bytes (if any) */
@ -395,7 +406,7 @@ hybiReadAndDecode(ws_ctx_t *wsctx, char *dst, int len, int *sockRet, int nInBuf)
errno = EIO; errno = EIO;
return WS_HYBI_STATE_ERR; return WS_HYBI_STATE_ERR;
} }
rfbLog("carrying over %d bytes from %p to %p\n", wsctx->carrylen, wsctx->writePos + (i * 4), wsctx->carryBuf); ws_dbg("carrying over %d bytes from %p to %p\n", wsctx->carrylen, wsctx->writePos + (i * 4), wsctx->carryBuf);
memcpy(wsctx->carryBuf, data + (i * 4), wsctx->carrylen); memcpy(wsctx->carryBuf, data + (i * 4), wsctx->carrylen);
wsctx->writePos -= wsctx->carrylen; wsctx->writePos -= wsctx->carrylen;
} }
@ -407,12 +418,12 @@ hybiReadAndDecode(ws_ctx_t *wsctx, char *dst, int len, int *sockRet, int nInBuf)
/* this data is not returned as payload data */ /* this data is not returned as payload data */
if (hybiWsFrameComplete(wsctx)) { if (hybiWsFrameComplete(wsctx)) {
*(wsctx->writePos) = '\0'; *(wsctx->writePos) = '\0';
rfbLog("got close cmd %d, reason %d: %s\n", (int)(wsctx->writePos - hybiPayloadStart(wsctx)), WS_NTOH16(((uint16_t *)hybiPayloadStart(wsctx))[0]), &hybiPayloadStart(wsctx)[2]); ws_dbg("got close cmd %d, reason %d: %s\n", (int)(wsctx->writePos - hybiPayloadStart(wsctx)), WS_NTOH16(((uint16_t *)hybiPayloadStart(wsctx))[0]), &hybiPayloadStart(wsctx)[2]);
errno = ECONNRESET; errno = ECONNRESET;
*sockRet = -1; *sockRet = -1;
return WS_HYBI_STATE_FRAME_COMPLETE; return WS_HYBI_STATE_FRAME_COMPLETE;
} else { } else {
rfbLog("got close cmd; waiting for %d more bytes to arrive\n", hybiRemaining(wsctx)); ws_dbg("got close cmd; waiting for %d more bytes to arrive\n", hybiRemaining(wsctx));
*sockRet = -1; *sockRet = -1;
errno = EAGAIN; errno = EAGAIN;
return WS_HYBI_STATE_CLOSE_REASON_PENDING; return WS_HYBI_STATE_CLOSE_REASON_PENDING;
@ -420,7 +431,7 @@ hybiReadAndDecode(ws_ctx_t *wsctx, char *dst, int len, int *sockRet, int nInBuf)
break; break;
case WS_OPCODE_TEXT_FRAME: case WS_OPCODE_TEXT_FRAME:
data[toReturn] = '\0'; data[toReturn] = '\0';
rfbLog("Initiate Base64 decoding in %p with max size %d and '\\0' at %p\n", data, bufsize, data + toReturn); ws_dbg("Initiate Base64 decoding in %p with max size %d and '\\0' at %p\n", data, bufsize, data + toReturn);
if (-1 == (wsctx->readlen = b64_pton((char *)data, data, bufsize))) { if (-1 == (wsctx->readlen = b64_pton((char *)data, data, bufsize))) {
rfbErr("%s: Base64 decode error; %s\n", __func__, strerror(errno)); rfbErr("%s: Base64 decode error; %s\n", __func__, strerror(errno));
} }
@ -429,7 +440,7 @@ hybiReadAndDecode(ws_ctx_t *wsctx, char *dst, int len, int *sockRet, int nInBuf)
case WS_OPCODE_BINARY_FRAME: case WS_OPCODE_BINARY_FRAME:
wsctx->readlen = toReturn; wsctx->readlen = toReturn;
wsctx->writePos = hybiPayloadStart(wsctx); wsctx->writePos = hybiPayloadStart(wsctx);
rfbLog("set readlen=%d writePos=%p\n", wsctx->readlen, wsctx->writePos); ws_dbg("set readlen=%d writePos=%p\n", wsctx->readlen, wsctx->writePos);
break; break;
default: default:
rfbErr("%s: unhandled opcode %d, b0: %02x, b1: %02x\n", __func__, (int)wsctx->header.opcode, wsctx->header.data->b0, wsctx->header.data->b1); rfbErr("%s: unhandled opcode %d, b0: %02x, b1: %02x\n", __func__, (int)wsctx->header.opcode, wsctx->header.data->b0, wsctx->header.data->b1);
@ -476,8 +487,7 @@ webSocketsDecodeHybi(ws_ctx_t *wsctx, char *dst, int len)
int result = -1; int result = -1;
/* int fin; */ /* not used atm */ /* int fin; */ /* not used atm */
/* rfbLog(" <== %s[%d]: %d cl: %p, wsctx: %p-%p (%d)\n", __func__, gettid(), len, cl, wsctx, (char *)wsctx + sizeof(ws_ctx_t), sizeof(ws_ctx_t)); */ ws_dbg("%s_enter: len=%d; "
rfbLog("%s_enter: len=%d; "
"CTX: readlen=%d readPos=%p " "CTX: readlen=%d readPos=%p "
"writeTo=%p " "writeTo=%p "
"state=%d payloadtoRead=%d payloadRemaining=%llu " "state=%d payloadtoRead=%d payloadRemaining=%llu "
@ -520,9 +530,8 @@ webSocketsDecodeHybi(ws_ctx_t *wsctx, char *dst, int len)
/* single point of return, if someone has questions :-) */ /* single point of return, if someone has questions :-) */
spor: spor:
/* rfbLog("%s: ret: %d/%d\n", __func__, result, len); */
if (wsctx->hybiDecodeState == WS_HYBI_STATE_FRAME_COMPLETE) { if (wsctx->hybiDecodeState == WS_HYBI_STATE_FRAME_COMPLETE) {
rfbLog("frame received successfully, cleaning up: read=%d hlen=%d plen=%d\n", wsctx->header.nRead, wsctx->header.headerLen, wsctx->header.payloadLen); ws_dbg("frame received successfully, cleaning up: read=%d hlen=%d plen=%d\n", wsctx->header.nRead, wsctx->header.headerLen, wsctx->header.payloadLen);
if (wsctx->header.fin && !isControlFrame(wsctx)) { if (wsctx->header.fin && !isControlFrame(wsctx)) {
/* frame finished, cleanup state */ /* frame finished, cleanup state */
hybiDecodeCleanupComplete(wsctx); hybiDecodeCleanupComplete(wsctx);
@ -535,7 +544,7 @@ spor:
hybiDecodeCleanupComplete(wsctx); hybiDecodeCleanupComplete(wsctx);
} }
rfbLog("%s_exit: len=%d; " ws_dbg("%s_exit: len=%d; "
"CTX: readlen=%d readPos=%p " "CTX: readlen=%d readPos=%p "
"writePos=%p " "writePos=%p "
"state=%d payloadtoRead=%d payloadRemaining=%d " "state=%d payloadtoRead=%d payloadRemaining=%d "

Write Preview
Loading…
Cancel
Save