search

status-im / nim-websock

Websocket for Nim
82 stars 15 forks source link

Test unit pass but debug log show suspicious "Connection isn't open, abortig close sequence!" #39

Open jangko opened 3 years ago

jangko commented 3 years ago

in the CI, tests is run with debug log suppressed. but when we enable chronicles log, it start to produce alarming messages. but the test still pass.

DBG 2021-05-27 10:37:29.261+07:00 Sending data to remote                     tid=1569 opcode=Text masked=true dataSize=11
DBG 2021-05-27 10:37:29.261+07:00 Sending data to remote                     tid=1569 opcode=Close masked=true dataSize=2
DBG 2021-05-27 10:37:29.261+07:00 Decoded new frame                          tid=1569 opcode=Text len=11 mask=true
DBG 2021-05-27 10:37:29.311+07:00 Decoded new frame                          tid=1569 opcode=Close len=2 mask=true
DBG 2021-05-27 10:37:29.311+07:00 Handling close sequence                    tid=1569 readyState=Open fin=true opcode=Close masked=true
DBG 2021-05-27 10:37:29.311+07:00 Sending data to remote                     tid=1569 opcode=Close masked=false dataSize=2
DBG 2021-05-27 10:37:29.311+07:00 Decoded new frame                          tid=1569 opcode=Close len=2 mask=false
DBG 2021-05-27 10:37:29.311+07:00 Handling close sequence                    tid=1569 readyState=Closing fin=true opcode=Close masked=false
DBG 2021-05-27 10:37:29.311+07:00 Connection isn't open, abortig close sequence! tid=1569 readyState=Closing fin=true opcode=Close masked=false
DBG 2021-05-27 10:37:29.311+07:00 Exception reading frame, dropping socket   tid=1569 exc="Incomplete data sent or received"
DBG 2021-05-27 10:37:29.311+07:00 Exception reading frames                   tid=1569 exc="Incomplete data sent or received"

many of test cases from tests/testwebsockets.nim show this message. is this ok? or is this an indicator something goes wrong? shouldn't we be more cautious about this?

dryajov commented 3 years ago

Closing flow needs to be revisited.