eap - Case 5.19 : Fail - 1019 ms @ 2014-05-30T11:25:44Z

Case Description
A fragmented text message is sent in multiple frames. After sending the first 2 frames of the text message, a Ping is sent. Then we wait 1s, then we send 2 more text fragments, another Ping and then the final text fragment. Everything is legal.

Case Expectation
The peer immediately answers the first Ping before it has received the last text message fragment. The peer pong's back the Ping's payload exactly, and echo's the payload of the fragmented message back to us.

Case Outcome
Actual events differ from any expected.
Expected:
{'OK': [('pong', u'pongme 1!'), ('pong', u'pongme 2!'), ('message', u'fragment1fragment2fragment3fragment4fragment5', False)]}
Observed:
[('pong', u'pongme 1!')]

Case Closing Behavior
The spec requires the connection to be failed cleanly here (UNCLEAN)

## Opening Handshake

    GET /jboss-as-autobahn/ HTTP/1.1
    User-Agent: AutobahnTestSuite/0.6.1-0.8.8
    Host: localhost:8080
    Upgrade: WebSocket
    Connection: Upgrade
    Pragma: no-cache
    Cache-Control: no-cache
    Sec-WebSocket-Key: U2w01yAyDT/1ZUTFZTaAXA==
    Sec-WebSocket-Version: 13

    HTTP/1.1 101 Switching Protocols
    Server: Apache-Coyote/1.1
    Upgrade: websocket
    Connection: upgrade
    Sec-WebSocket-Accept: eHcVJ+3nYILMTS8uvCAqYNJYHhM=
    Date: Fri, 30 May 2014 11:25:44 GMT

## Closing Behavior

Key | Value | Description
isServer | False | True, iff I (the fuzzer) am a server, and the peer is a client.
closedByMe | True | True, iff I have initiated closing handshake (that is, did send close first).
failedByMe | True | True, iff I have failed the WS connection (i.e. due to protocol error). Failing can be either by initiating closing handshake or brutal drop TCP.
droppedByMe | True | True, iff I dropped the TCP connection.
wasClean | False | True, iff full WebSockets closing handshake was performed (close frame sent and received) _and_ the server dropped the TCP (which is its responsibility).
wasNotCleanReason | peer did not respond (in time) in closing handshake | When wasClean == False, the reason what happened.
wasServerConnectionDropTimeout | False | When we are a client, and we expected the server to drop the TCP, but that didn't happen in time, this gets True.
wasOpenHandshakeTimeout | False | When performing the opening handshake, but the peer did not finish in time, this gets True.
wasCloseHandshakeTimeout | True | When we initiated a closing handshake, but the peer did not respond in time, this gets True.
localCloseCode | 1002 | The close code I sent in close frame (if any).
localCloseReason | RSV = 7 and no extension negotiated | The close reason I sent in close frame (if any).
remoteCloseCode | None | The close code the peer sent me in close frame (if any).
remoteCloseReason | None | The close reason the peer sent me in close frame (if any).

## Wire Statistics

### Octets Received by Chop Size

Chop Size | Count | Octets
11 | 3 | 33
125 | 1 | 125
193 | 1 | 193
Total | 5 | 351

### Octets Transmitted by Chop Size

Chop Size | Count | Octets
15 | 7 | 105
43 | 1 | 43
257 | 1 | 257
Total | 9 | 405

### Frames Received by Opcode

Opcode | Count
0 | 8
1 | 1
10 | 1
Total | 10

### Frames Transmitted by Opcode

Opcode | Count
0 | 4
1 | 1
8 | 1
9 | 2
Total | 8

## Wire Log

    000 TX OCTETS: 474554202f6a626f73732d61732d6175746f6261686e2f20485454502f312e310d0a557365722d4167656e743a204175746f

                   6261686e5465737453756974652f ...

    001 RX OCTETS: 485454502f312e312031303120537769746368696e672050726f746f636f6c730d0a5365727665723a204170616368652d43

                   6f796f74652f312e310d0a557067 ...

    002 TX FRAME : OPCODE=1, FIN=False, RSV=0, PAYLOAD-LEN=9, MASK=140cbfdc, PAYLOAD-REPEAT-LEN=None, CHOPSIZE=None, SYNC=False

                   fragment1

    003 TX OCTETS: 0189140cbfdc727edebb7969d1a825

    004 TX FRAME : OPCODE=0, FIN=False, RSV=0, PAYLOAD-LEN=9, MASK=4b494fd8, PAYLOAD-REPEAT-LEN=None, CHOPSIZE=None, SYNC=False

                   fragment2

    005 TX OCTETS: 00894b494fd82d3b2ebf262c21ac79

    006 TX FRAME : OPCODE=9, FIN=True, RSV=0, PAYLOAD-LEN=9, MASK=2bf1b515, PAYLOAD-REPEAT-LEN=None, CHOPSIZE=None, SYNC=False

                   pongme 1!

    007 TX OCTETS: 89892bf1b5155b9edb72469495240a

    008 DELAY 1.000000 sec for TAG None

    009 RX OCTETS: 0109667261676d656e7431

    010 RX FRAME : OPCODE=1, FIN=False, RSV=0, PAYLOAD-LEN=9, MASKED=False, MASK=None

                   fragment1

    011 RX OCTETS: 0009667261676d656e7432

    012 RX FRAME : OPCODE=0, FIN=False, RSV=0, PAYLOAD-LEN=9, MASKED=False, MASK=None

                   fragment2

    013 RX OCTETS: 8a09706f6e676d65203121

    014 RX FRAME : OPCODE=10, FIN=True, RSV=0, PAYLOAD-LEN=9, MASKED=False, MASK=None

                   pongme 1!

    015 RX OCTETS: 706f6e676d652031210000000000000000000000000000000000000000000000000000000000000000000000000000000000

                   0000000000000000000000000000 ...

    016 TX FRAME : OPCODE=8, FIN=True, RSV=0, PAYLOAD-LEN=37, MASK=5bac299f, PAYLOAD-REPEAT-LEN=None, CHOPSIZE=None, SYNC=False

                   0x03ea525356203d203720616e64206e6f20657874656e73696f6e206e65676f746961746564

    017 TX OCTETS: 88a55bac299f58467bcc0d8c14bf6c8c48f13f8c47f07bc951eb3ec25af634c209f13ecb46eb32cd5dfa3f

    018 RX FRAME : OPCODE=0, FIN=False, RSV=7, PAYLOAD-LEN=0, MASKED=False, MASK=None

    019 RX FRAME : OPCODE=0, FIN=False, RSV=0, PAYLOAD-LEN=0, MASKED=False, MASK=None

    020 RX FRAME : OPCODE=0, FIN=False, RSV=0, PAYLOAD-LEN=0, MASKED=False, MASK=None

    021 RX FRAME : OPCODE=0, FIN=False, RSV=0, PAYLOAD-LEN=0, MASKED=False, MASK=None

    022 RX FRAME : OPCODE=0, FIN=False, RSV=0, PAYLOAD-LEN=0, MASKED=False, MASK=None

    023 RX FRAME : OPCODE=0, FIN=False, RSV=0, PAYLOAD-LEN=0, MASKED=False, MASK=None

    024 RX FRAME : OPCODE=0, FIN=False, RSV=0, PAYLOAD-LEN=0, MASKED=False, MASK=None

    025 DELAY TIMEOUT on TAG None

    026 TX FRAME : OPCODE=0, FIN=False, RSV=0, PAYLOAD-LEN=9, MASK=02cb4775, PAYLOAD-REPEAT-LEN=None, CHOPSIZE=None, SYNC=False

                   fragment3

    027 TX OCTETS: 008902cb477564b926126fae290131

    028 TX FRAME : OPCODE=0, FIN=False, RSV=0, PAYLOAD-LEN=9, MASK=b77746bd, PAYLOAD-REPEAT-LEN=None, CHOPSIZE=None, SYNC=False

                   fragment4

    029 TX OCTETS: 0089b77746bdd10527dada1228c983

    030 TX FRAME : OPCODE=9, FIN=True, RSV=0, PAYLOAD-LEN=9, MASK=0053db21, PAYLOAD-REPEAT-LEN=None, CHOPSIZE=None, SYNC=False

                   pongme 2!

    031 TX OCTETS: 89890053db21703cb5466d36fb1321

    032 TX FRAME : OPCODE=0, FIN=True, RSV=0, PAYLOAD-LEN=9, MASK=7a95c4cc, PAYLOAD-REPEAT-LEN=None, CHOPSIZE=None, SYNC=False

                   fragment5

    033 TX OCTETS: 80897a95c4cc1ce7a5ab17f0aab84f

    034 CLOSE CONNECTION AFTER 1.000000 sec

    035 TCP DROPPED BY ME