cancel
Showing results for 
Search instead for 
Did you mean: 
Login & Join the DevCentral Connects Group to watch the Recorded LiveStream (May 12) on Basic iControl Security - show notes included.
Kimihito
F5 Employee
F5 Employee

Problem this snippet solves:

WebSocket establishes a socket via HTTP upgrade and once socket is established subsequent messages are non-HTTP, but WebSocket frame.

There might be a situation where you want to dump WebSocket negotiation and frame into log for troubleshooting purpose. This iRule dumps negotiation and WebSocket frame header fields, and payload (only text data).

WebSocket frame format looks as below.

RFC 6455 - 5.2. Base Framing Protocol

  0                   1                   2                   3
  0 1 2 3 4 5 6 7 8 9 0 1 2 3 4 5 6 7 8 9 0 1 2 3 4 5 6 7 8 9 0 1
 +-+-+-+-+-------+-+-------------+-------------------------------+
 |F|R|R|R| opcode|M| Payload len |    Extended payload length    |
 |I|S|S|S|  (4)  |A|     (7)     |             (16/64)           |
 |N|V|V|V|       |S|             |   (if payload len==126/127)   |
 | |1|2|3|       |K|             |                               |
 +-+-+-+-+-------+-+-------------+ - - - - - - - - - - - - - - - +
 |     Extended payload length continued, if payload len == 127  |
 + - - - - - - - - - - - - - - - +-------------------------------+
 |                               |Masking-key, if MASK set to 1  |
 +-------------------------------+-------------------------------+
 | Masking-key (continued)       |          Payload Data         |
 +-------------------------------- - - - - - - - - - - - - - - - +
 :                     Payload Data continued ...                :
 + - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - +
 |                     Payload Data continued ...                |
 +---------------------------------------------------------------+

WebSocket frame is quite simple. The first 2 bytes are necessary and always present. Extended payload length exists only when Payload length is set to 126 (in this case Ext len is 16 bits) or 127 (in this case Ext len is 64 bits). Masking-key exists only if MASK bit is set to 1.

FIN : If the frame is the last frame, set to 1. If payload is fragmented, the last frame should have FIN = 1. Other fragmented ones should have FIN = 0.

RSV : If extension is not used, it is set to 0

opcode : This tells you if it is data frame (can be text or binary) or control frame. %x0:continuation frame %x1:text frame %x2:binary frame %x3-7:reserved for further %x8:connection close %x9:ping %xA:pong %xB-F:reserved for further

MASK : When browser sends a data, this bit MUST be set to 1, which means data is masked using the Masking-key. When server sends a data, this bit MUST NOT set to 1

Payload len : If 0 - 125, this field represents the payload length If it is 126, then the Extended payload length (16bit) are used to tell the actual payload length (maximum data size is 65535 bytes) If it is 127, then the Extended payload length (64bit : MSB must be 0) are used to tell the actual payload length (maximum data size is 9223372036854775807 bytes)

Extended payload length Only when Payload len is set to 126

Extended payload length_continued Only when Payload len is set to 127

Masking-key Used to mask data. Masking is to avoid proxy poisoning. Non-compliant HTTP proxy caches WebSocket data. If MASK bit is 1, this field is present. If MASK bit is 0, this field is not present. Client sets this key and it must be unpredictable.

Payload Payload from client to server is masked using Masking-key.

How to use this snippet:

Here I am sending text data "DEAD BEEF" in WebSocket frame via WebSocket_cURL.py (https://github.com/jussmen/WebSocket_cURL). HTTP request and response (negotiation) look like below.

$ python WebSocket_cURL.py 10.10.148.101 80 -s "DEAD BEEF"
GET /ws HTTP/1.1
Host: 10.10.148.101
Connection: Upgrade
Upgrade: websocket
Sec-WebSocket-Version: 13
Sec-WebSocket-Key: n5twxG/tNPf8h3po+pNrPA==
User-Agent: IE

HTTP/1.1 101 Switching Protocols
Upgrade: websocket
Connection: Upgrade
Sec-WebSocket-Accept: y9WDs+d4zDl+qvQ7H17KpnP0EhI=

This is how iRule dumps the negotiation and subsequent WebSocket frames in /var/log/ltm

<ws_request>: =============================================
<ws_request>: Client 10.10.1.2:47427 -> 10.10.148.101/ws (request)
<ws_request>: Host: 10.10.148.101
<ws_request>: Connection: Upgrade
<ws_request>: Upgrade: websocket
<ws_request>: Sec-WebSocket-Version: 13
<ws_request>: Sec-WebSocket-Key: n5twxG/tNPf8h3po+pNrPA==
<ws_request>: User-Agent: IE
<ws_request>: =============================================
<ws_response>: =============================================
<ws_response>: Client 10.10.1.2:47427 -> 10.10.148.101/ws (response)
<ws_response>: Upgrade: websocket
<ws_response>: Connection: Upgrade
<ws_response>: Sec-WebSocket-Accept: y9WDs+d4zDl+qvQ7H17KpnP0EhI=
<ws_response>: =============================================
<ws_server_frame>: =============================================
<ws_server_frame>: FIN bit  : 1
<ws_server_frame>: MASK bit : 1
<ws_server_frame>: MASK     : 0
<ws_server_frame>: Type     : Text - 1
<ws_server_frame>: =============================================
<ws_server_data>: =============================================
<ws_server_data>: The server says: 'Hello'. Connection was accepted.
<ws_server_data>: =============================================
<ws_client_frame>: =============================================
<ws_client_frame>: FIN bit  : 1
<ws_client_frame>: MASK bit : 1
<ws_client_frame>: MASK     : 1178944834
<ws_client_frame>: Type     : Text - 1
<ws_client_frame>: =============================================
<ws_client_data>: =============================================
<ws_client_data>: DEAD BEEF
<ws_client_data>: =============================================
<ws_server_frame>: =============================================
<ws_server_frame>: FIN bit  : 1
<ws_server_frame>: MASK bit : 1
<ws_server_frame>: MASK     : 0
<ws_server_frame>: Type     : Text - 1
<ws_server_frame>: =============================================
<ws_server_data>: =============================================
<ws_server_data>: The server says: DEAD BEEF back at you
<ws_server_data>: =============================================
<ws_client_frame>: =============================================
<ws_client_frame>: FIN bit  : 1
<ws_client_frame>: MASK bit : 1
<ws_client_frame>: MASK     : 1178944834
<ws_client_frame>: Type     : Connection close - 8
<ws_client_frame>: =============================================
<ws_server_frame>: =============================================
<ws_server_frame>: FIN bit  : 1
<ws_server_frame>: MASK bit : 1
<ws_server_frame>: MASK     : 0
<ws_server_frame>: Type     : Connection close - 8
<ws_server_frame>: =============================================

Code :

when WS_REQUEST {
    # Copied from : https://devcentral.f5.com/s/articles/log-http-headers
    set LogString "Client [IP::client_addr]:[TCP::client_port] -> [HTTP::host][HTTP::uri]"
    log local0. "============================================="
    log local0. "$LogString (request)"
    foreach aHeader [HTTP::header names] {
        log local0. "$aHeader: [HTTP::header value $aHeader]"
    }
    log local0. "============================================="
}
when WS_RESPONSE {
    # Copied from : https://devcentral.f5.com/s/articles/log-http-headers
    log local0. "============================================="
    log local0. "$LogString (response)"
    foreach aHeader [HTTP::header names] {
        log local0. "$aHeader: [HTTP::header value $aHeader]"
    }
    log local0. "=============================================" 
}
when WS_CLIENT_FRAME {
    log local0. "============================================="
    log local0. "FIN bit  : [WS::frame eom]"
    log local0. "MASK bit : [WS::frame orig_masked]"
    if { [WS::frame orig_masked] eq 0 } {
        log local0. "Not masked. Client frame MUST be masked."
    }  
    if { [WS::frame orig_masked] eq 1 } {
        log local0. "MASK     : [WS::frame mask]"
    }
    switch -glob [WS::frame type] {
        "0" { log local0. "Type     : Continuatoin frame - 0" }
        "1" { 
            log local0. "Type     : Text - 1"
            WS::collect frame
            }
        "2" { log local0. "Type     : Binary - 2" }
        "3" -
        "4" -
        "5" -
        "6" -
        "7" { log local0. "Type     : Reserved type (3-7) - [WS::frame type]" }
        "8" { log local0. "Type     : Connection close - 8" }
        "9" { log local0. "Type     : ping - 9" }
        "10" { log local0. "Type    : pong - 10" }
        "11" -
        "12" -
        "13" -
        "14" -
        "15" { log local0. "Type     : Reserved type (11-15) - [WS::frame type]" }
    }
    log local0. "============================================="
}
when WS_SERVER_FRAME {
    log local0. "============================================="
    log local0. "FIN bit  : [WS::frame eom]"
    log local0. "MASK bit : [WS::frame orig_masked]"
    if { [WS::frame orig_masked] eq 1 } {
        log local0. "MASK     : [WS::frame mask]"
    }
    switch -glob [WS::frame type] {
        "0" { log local0. "Type     : Continuatoin frame - 0" }
        "1" { 
            log local0. "Type     : Text - 1"
            WS::collect frame
            }
        "2" { log local0. "Type     : Binary - 2" }
        "3" -
        "4" -
        "5" -
        "6" -
        "7" { log local0. "Type     : Reserved type (3-7) - [WS::frame type]" }
        "8" { log local0. "Type     : Connection close - 8" }
        "9" { log local0. "Type     : ping - 9" }
        "10" { log local0. "Type    : pong - 10" }
        "11" -
        "12" -
        "13" -
        "14" -
        "15" { log local0. "Type     : Reserved type (11-15) - [WS::frame type]" }
    }
    log local0. "============================================="
}
#when WS_CLIENT_FRAME_DONE {
#log local0. "WS_CLIENT_FRAME_DONE"
#}
#when WS_SERVER_FRAME_DONE {
#log local0. "WS_SERVER_FRAME_DONE"
#}

when WS_CLIENT_DATA {
    log local0. "============================================="
    log local0. "[WS::payload]"
    log local0. "============================================="
    WS::release
}
when WS_SERVER_DATA {
    log local0. "============================================="
    log local0. "[WS::payload]"
    log local0. "============================================="
    WS::release
}

Tested this on version:

12.0
Version history
Last update:
‎30-Jun-2016 07:12
Updated by:
Contributors