Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Sometimes TestSettlementHS/Do fails #185

Closed
nkryuchkov opened this issue Mar 3, 2020 · 1 comment · Fixed by #190 or #203
Closed

Sometimes TestSettlementHS/Do fails #185

nkryuchkov opened this issue Mar 3, 2020 · 1 comment · Fixed by #190 or #203
Assignees
@nkryuchkov
Labels
bug Something isn't working

Comments

@nkryuchkov
Copy link
Contributor

Describe the bug

[2020-03-03T21:41:38+01:00] INFO [dmsg_server]: Serving server. local_addr="" local_pk=021584f99b9dc3dfa757a0760c93e0bf44b443dacb474376b90eec7d32a2092865
[2020-03-03T21:41:38+01:00] INFO [dmsg_server]: Updating discovery entry... local_addr="" local_pk=021584f99b9dc3dfa757a0760c93e0bf44b443dacb474376b90eec7d32a2092865
[2020-03-03T21:41:39+01:00] INFO [dmsg_server]: Accepting sessions... local_addr="" local_pk=021584f99b9dc3dfa757a0760c93e0bf44b443dacb474376b90eec7d32a2092865
[2020-03-03T21:41:39+01:00] INFO [dmsg_client]: Discovering dmsg servers...
[2020-03-03T21:41:39+01:00] INFO [dmsg_client]: Dialing session... remote_pk=021584f99b9dc3dfa757a0760c93e0bf44b443dacb474376b90eec7d32a2092865
[2020-03-03T21:41:39+01:00] INFO [dmsg_client]: Discovering dmsg servers...
[2020-03-03T21:41:39+01:00] INFO [dmsg_server]: Started session. remote_pk=0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551 remote_tcp=127.0.0.1:55530
[2020-03-03T21:41:39+01:00] INFO [dmsg_client]: Discovering dmsg servers...
[2020-03-03T21:41:39+01:00] INFO [dmsg_client]: Dialing session... remote_pk=021584f99b9dc3dfa757a0760c93e0bf44b443dacb474376b90eec7d32a2092865
[2020-03-03T21:41:39+01:00] INFO [dmsg_client]: Discovering dmsg servers...
[2020-03-03T21:41:39+01:00] INFO [dmsg_client]: Discovering dmsg servers...
[2020-03-03T21:41:39+01:00] INFO [dmsg_client]: Serving session. remote_pk=021584f99b9dc3dfa757a0760c93e0bf44b443dacb474376b90eec7d32a2092865
[2020-03-03T21:41:39+01:00] INFO [dmsg_client]: Discovering dmsg servers...
[2020-03-03T21:41:39+01:00] INFO [dmsg_server]: Started session. remote_pk=02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3 remote_tcp=127.0.0.1:55535
[2020-03-03T21:41:39+01:00] INFO [dmsg_client]: Session closed. error=<nil>
[2020-03-03T21:41:39+01:00] INFO [dmsg_client]: Session stopped. error=<nil>
[2020-03-03T21:41:39+01:00] INFO [dmsg_client]: Stopped serving client!
[2020-03-03T21:41:39+01:00] INFO [dmsg_client]: All sessions closed.
[2020-03-03T21:41:39+01:00] WARN [dmsg_client]: Stopped accepting streams. error="session shutdown" session=021584f99b9dc3dfa757a0760c93e0bf44b443dacb474376b90eec7d32a2092865
[2020-03-03T21:41:39+01:00] INFO [dmsg_client]: Session stopped. error=<nil>
[2020-03-03T21:41:39+01:00] INFO [dmsg_client]: Stopped serving client!
[2020-03-03T21:41:39+01:00] INFO [dmsg_server]: Stopping session... error="EOF" session=0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551
[2020-03-03T21:41:39+01:00] INFO [dmsg_server]: Stopped session. error=<nil> remote_pk=0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551 remote_tcp=127.0.0.1:55530
[2020-03-03T21:41:39+01:00] INFO [dmsg_client]: Stopped serving client!
[2020-03-03T21:41:39+01:00] INFO [dmsg_client]: Stopped serving client!
[2020-03-03T21:41:39+01:00] INFO [dmsg_client]: Serving session. remote_pk=021584f99b9dc3dfa757a0760c93e0bf44b443dacb474376b90eec7d32a2092865
[2020-03-03T21:41:39+01:00] INFO [dmsg_server]: Stopping session... error="EOF" session=02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3
[2020-03-03T21:41:39+01:00] INFO [dmsg_client]: Session closed. error=<nil>
[2020-03-03T21:41:39+01:00] INFO [dmsg_client]: All sessions closed.
[2020-03-03T21:41:39+01:00] WARN [dmsg_client]: Stopped accepting streams. error="session shutdown" session=021584f99b9dc3dfa757a0760c93e0bf44b443dacb474376b90eec7d32a2092865
[2020-03-03T21:41:39+01:00] INFO [dmsg_server]: Stopped session. error=<nil> remote_pk=02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3 remote_tcp=127.0.0.1:55535
[2020-03-03T21:41:39+01:00] INFO [dmsg_server]: Stopped server. local_addr="" local_pk=021584f99b9dc3dfa757a0760c93e0bf44b443dacb474376b90eec7d32a2092865
--- FAIL: TestSettlementHS (1.54s)
    --- FAIL: TestSettlementHS/Do (0.00s)
        handshake_test.go:39: 
                Error Trace:    handshake_test.go:39
                Error:          Received unexpected error:
                                dmsg error 100 - entry is not found in discovery
                Test:           TestSettlementHS/Do
[2020-03-03T21:41:39+01:00] INFO [dmsg_server]: Stopping server, net.Listener closed. error=<nil> local_addr="" local_pk=021584f99b9dc3dfa757a0760c93e0bf44b443dacb474376b90eec7d32a2092865
{"recv":100,"sent":10}
{
        "recv": 100,
        "sent": 10
}
[2020-03-03T21:41:40+01:00] INFO [dmsg_server]: Serving server. local_addr="" local_pk=021584f99b9dc3dfa757a0760c93e0bf44b443dacb474376b90eec7d32a2092865
[2020-03-03T21:41:40+01:00] INFO [dmsg_server]: Updating discovery entry... local_addr="" local_pk=021584f99b9dc3dfa757a0760c93e0bf44b443dacb474376b90eec7d32a2092865
[2020-03-03T21:41:40+01:00] INFO [dmsg_server]: Accepting sessions... local_addr="" local_pk=021584f99b9dc3dfa757a0760c93e0bf44b443dacb474376b90eec7d32a2092865
[2020-03-03T21:41:40+01:00] INFO [dmsg_client]: Discovering dmsg servers...
[2020-03-03T21:41:40+01:00] INFO [dmsg_client]: Dialing session... remote_pk=021584f99b9dc3dfa757a0760c93e0bf44b443dacb474376b90eec7d32a2092865
[2020-03-03T21:41:40+01:00] INFO [dmsg_client]: Discovering dmsg servers...
[2020-03-03T21:41:40+01:00] INFO [dmsg_server]: Started session. remote_pk=0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551 remote_tcp=127.0.0.1:55541
[2020-03-03T21:41:40+01:00] INFO [dmsg_client]: Discovering dmsg servers...
[2020-03-03T21:41:40+01:00] INFO [dmsg_client]: Serving session. remote_pk=021584f99b9dc3dfa757a0760c93e0bf44b443dacb474376b90eec7d32a2092865
[2020-03-03T21:41:40+01:00] INFO [dmsg_client]: Discovering dmsg servers...
[2020-03-03T21:41:40+01:00] INFO [dmsg_client]: Discovering dmsg servers...
[2020-03-03T21:41:40+01:00] INFO [dmsg_client]: Dialing session... remote_pk=021584f99b9dc3dfa757a0760c93e0bf44b443dacb474376b90eec7d32a2092865
[2020-03-03T21:41:41+01:00] INFO [dmsg_client]: Discovering dmsg servers...
[2020-03-03T21:41:41+01:00] INFO [dmsg_server]: Started session. remote_pk=02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3 remote_tcp=127.0.0.1:55548
[2020-03-03T21:41:41+01:00] INFO [dmsg_client]: Discovering dmsg servers...
[2020-03-03T21:41:41+01:00] INFO [dmsg_client]: Serving session. remote_pk=021584f99b9dc3dfa757a0760c93e0bf44b443dacb474376b90eec7d32a2092865
[2020-03-03T21:41:41+01:00] INFO [dmsg_client]: Discovering dmsg servers...
[2020-03-03T21:41:41+01:00] DEBUG [tp_manager]: Initializing TP with ID d1b729dd-152e-0cd0-ad3a-98e96b1f97ae
[2020-03-03T21:41:41+01:00] INFO [tp_manager]: saved transport: remote(0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551) type(dmsg) tpID(d1b729dd-152e-0cd0-ad3a-98e96b1f97ae)
[2020-03-03T21:41:41+01:00] INFO [tp:034532]: serving: tpID(d1b729dd-152e-0cd0-ad3a-98e96b1f97ae) rPK(0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551) srvQty[1]
[2020-03-03T21:41:41+01:00] INFO [tp_manager]: listening on network: dmsg
[2020-03-03T21:41:41+01:00] INFO [dmsg_server]: Serving stream. session=02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3
[2020-03-03T21:41:41+01:00] DEBUG [tp_manager]: Initializing 0 transports
[2020-03-03T21:41:41+01:00] INFO [tp_manager]: transport manager is serving.
[2020-03-03T21:41:41+01:00] INFO [tp_manager]: listening on network: dmsg
[2020-03-03T21:41:41+01:00] INFO [tp_manager]: recv transport connection request: type(dmsg) remote(02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3)
[2020-03-03T21:41:41+01:00] DEBUG [tp_manager]: No TP found, creating new one
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Performing handshake...
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Setting TP conn...
[2020-03-03T21:41:41+01:00] INFO [tp:02d75d]: Status updated: UP
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Sent signal to connCh
[2020-03-03T21:41:41+01:00] INFO [tp:034532]: Status updated: UP
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Sent signal to connCh
[2020-03-03T21:41:41+01:00] INFO [tp_manager]: accepted tp: type(dmsg) remote(02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3) tpID(d1b729dd-152e-0cd0-ad3a-98e96b1f97ae) new(true)
transports created
[2020-03-03T21:41:41+01:00] DEBUG [tp_manager]: Initializing 1 transports
[2020-03-03T21:41:41+01:00] INFO [tp:02d75d]: serving: tpID(d1b729dd-152e-0cd0-ad3a-98e96b1f97ae) rPK(02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3) srvQty[1]
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Got conn in managed TP: 0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551:45
[2020-03-03T21:41:41+01:00] DEBUG [tp_manager]: Initializing TP {d1b729dd-152e-0cd0-ad3a-98e96b1f97ae [02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3 0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551] dmsg true}
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Got conn in managed TP: 02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3:49153
[2020-03-03T21:41:41+01:00] DEBUG [tp_manager]: Initializing TP with ID d1b729dd-152e-0cd0-ad3a-98e96b1f97ae
[2020-03-03T21:41:41+01:00] DEBUG [tp_manager]: Got TP from map
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp_manager]: Successfully initialized TP {d1b729dd-152e-0cd0-ad3a-98e96b1f97ae [02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3 0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551] dmsg true}
[2020-03-03T21:41:41+01:00] INFO [tp_manager]: transport manager is serving.
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Read packet payload: 
[2020-03-03T21:41:41+01:00] INFO [tp:02d75d]: recv packet: type (DataPacket) rtID(0) size(0)
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Got conn in managed TP: 02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3:49153
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Read packet payload: 
[2020-03-03T21:41:41+01:00] INFO [tp:02d75d]: recv packet: type (DataPacket) rtID(1) size(1)
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Got conn in managed TP: 02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3:49153
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Read packet payload: 5
[2020-03-03T21:41:41+01:00] INFO [tp:02d75d]: recv packet: type (DataPacket) rtID(2) size(2)
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Got conn in managed TP: 02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3:49153
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Read packet payload: X�r
[2020-03-03T21:41:41+01:00] INFO [tp:02d75d]: recv packet: type (DataPacket) rtID(3) size(3)
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Got conn in managed TP: 02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3:49153
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Read packet payload: ��_�
[2020-03-03T21:41:41+01:00] INFO [tp:02d75d]: recv packet: type (DataPacket) rtID(4) size(4)
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Got conn in managed TP: 02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3:49153
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Read packet payload: �j�X
[2020-03-03T21:41:41+01:00] INFO [tp:02d75d]: recv packet: type (DataPacket) rtID(5) size(5)
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Got conn in managed TP: 02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3:49153
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Read packet payload: ���i?�
[2020-03-03T21:41:41+01:00] INFO [tp:02d75d]: recv packet: type (DataPacket) rtID(6) size(6)
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Got conn in managed TP: 02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3:49153
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Read packet payload: �Ij,�Y�
[2020-03-03T21:41:41+01:00] INFO [tp:02d75d]: recv packet: type (DataPacket) rtID(7) size(7)
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Got conn in managed TP: 02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3:49153
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Read packet payload: �!�UZ$4
[2020-03-03T21:41:41+01:00] INFO [tp:02d75d]: recv packet: type (DataPacket) rtID(8) size(8)
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Got conn in managed TP: 02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3:49153
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Read packet header:              
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Read packet payload: uI�ʢh+z
[2020-03-03T21:41:41+01:00] INFO [tp:02d75d]: recv packet: type (DataPacket) rtID(9) size(9)
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Got conn in managed TP: 02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3:49153
[2020-03-03T21:41:41+01:00] DEBUG [tp:02d75d]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet payload: 
[2020-03-03T21:41:41+01:00] INFO [tp:034532]: recv packet: type (DataPacket) rtID(0) size(0)
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Got conn in managed TP: 0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551:45
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet payload: �
[2020-03-03T21:41:41+01:00] INFO [tp:034532]: recv packet: type (DataPacket) rtID(1) size(1)
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Got conn in managed TP: 0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551:45
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet payload: �
[2020-03-03T21:41:41+01:00] INFO [tp:034532]: recv packet: type (DataPacket) rtID(2) size(2)
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Got conn in managed TP: 0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551:45
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet payload: S�
[2020-03-03T21:41:41+01:00] INFO [tp:034532]: recv packet: type (DataPacket) rtID(3) size(3)
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Got conn in managed TP: 0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551:45
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet payload: �ZP�
[2020-03-03T21:41:41+01:00] INFO [tp:034532]: recv packet: type (DataPacket) rtID(4) size(4)
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Got conn in managed TP: 0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551:45
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet payload: 
                                                                    ���
[2020-03-03T21:41:41+01:00] INFO [tp:034532]: recv packet: type (DataPacket) rtID(5) size(5)
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Got conn in managed TP: 0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551:45
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet payload: �K`z�Y
[2020-03-03T21:41:41+01:00] INFO [tp:034532]: recv packet: type (DataPacket) rtID(6) size(6)
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Got conn in managed TP: 0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551:45
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet payload: 9��q��
[2020-03-03T21:41:41+01:00] INFO [tp:034532]: recv packet: type (DataPacket) rtID(7) size(7)
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Got conn in managed TP: 0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551:45
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet payload: �_�35\��
[2020-03-03T21:41:41+01:00] INFO [tp:034532]: recv packet: type (DataPacket) rtID(8) size(8)
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Got conn in managed TP: 0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551:45
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet header:              
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet payload: *�����U##
[2020-03-03T21:41:41+01:00] INFO [tp:034532]: recv packet: type (DataPacket) rtID(9) size(9)
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Got conn in managed TP: 0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551:45
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet header: 


[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet payload: ��2���"1P
[2020-03-03T21:41:41+01:00] INFO [tp:034532]: recv packet: type (DataPacket) rtID(10) size(10)
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Got conn in managed TP: 0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551:45
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet header: 


[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet payload: ">Cb��jm
[2020-03-03T21:41:41+01:00] INFO [tp:034532]: recv packet: type (DataPacket) rtID(11) size(11)
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Got conn in managed TP: 0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551:45
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet header: 


[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet payload: � ����߭�
[2020-03-03T21:41:41+01:00] INFO [tp:034532]: recv packet: type (DataPacket) rtID(12) size(12)
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Got conn in managed TP: 0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551:45
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet payload: Ys͊e�l`B:��N
[2020-03-03T21:41:41+01:00] INFO [tp:034532]: recv packet: type (DataPacket) rtID(13) size(13)
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Got conn in managed TP: 0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551:45
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet payload: x�ێ`$)4U�9�D�
[2020-03-03T21:41:41+01:00] INFO [tp:034532]: recv packet: type (DataPacket) rtID(14) size(14)
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Got conn in managed TP: 0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551:45
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet payload: �Ḍ�����    ���

[2020-03-03T21:41:41+01:00] INFO [tp:034532]: recv packet: type (DataPacket) rtID(15) size(15)
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Got conn in managed TP: 0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551:45
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet payload: �&�B�-"���������
[2020-03-03T21:41:41+01:00] INFO [tp:034532]: recv packet: type (DataPacket) rtID(16) size(16)
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Got conn in managed TP: 0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551:45
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet payload: �y���(�U�GP���
[2020-03-03T21:41:41+01:00] INFO [tp:034532]: recv packet: type (DataPacket) rtID(17) size(17)
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Got conn in managed TP: 0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551:45
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet payload: �]Ry�C��=��������
[2020-03-03T21:41:41+01:00] INFO [tp:034532]: recv packet: type (DataPacket) rtID(18) size(18)
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Got conn in managed TP: 0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551:45
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Trying to read packet header...
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet header: 
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Read packet payload: �S���T$J��yx|�
                                                                                  �
[2020-03-03T21:41:41+01:00] INFO [tp:034532]: recv packet: type (DataPacket) rtID(19) size(19)
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Got conn in managed TP: 0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551:45
[2020-03-03T21:41:41+01:00] DEBUG [tp:034532]: Trying to read packet header...
[2020-03-03T21:41:44+01:00] INFO [tp:034532]: entry log: recording 28 operations
[2020-03-03T21:41:44+01:00] INFO [tp:02d75d]: entry log: recording 28 operations
[2020-03-03T21:41:46+01:00] INFO [tp_manager]: Deregistered transport of ID d1b729dd-152e-0cd0-ad3a-98e96b1f97ae from discovery.
[2020-03-03T21:41:46+01:00] INFO [tp:034532]: stopped: tpID(d1b729dd-152e-0cd0-ad3a-98e96b1f97ae) rPK(0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551) srvQty[0]
[2020-03-03T21:41:46+01:00] DEBUG [tp:034532]: Failed to read packet header: EOF error="EOF"
[2020-03-03T21:41:46+01:00] WARN [tp:034532]: failed to read packet: EOF
[2020-03-03T21:41:46+01:00] DEBUG [tp:034532]: Failed to read packet error="transport is no longer being served"
[2020-03-03T21:41:46+01:00] INFO [tp:034532]: closed readPacket loop.
[2020-03-03T21:41:46+01:00] INFO [dmsg_server]: Stopped stream. error=<nil> session=02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3
[2020-03-03T21:41:46+01:00] DEBUG [tp:02d75d]: Failed to read packet header: EOF error="EOF"
[2020-03-03T21:41:46+01:00] INFO [tp_manager]: transport manager is closing.
[2020-03-03T21:41:46+01:00] WARN [tp:02d75d]: Failed to update transport status: transport not found
[2020-03-03T21:41:46+01:00] INFO [tp_manager]: transport manager closed.
[2020-03-03T21:41:46+01:00] WARN [tp:02d75d]: failed to read packet: EOF
[2020-03-03T21:41:46+01:00] WARN [tp_manager]: Failed to accept connection: dmsg error 200 - local entity closed
[2020-03-03T21:41:46+01:00] INFO [tp:02d75d]: stopped: tpID(d1b729dd-152e-0cd0-ad3a-98e96b1f97ae) rPK(02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3) srvQty[0]
[2020-03-03T21:41:46+01:00] INFO [tp_manager]: transport manager is closing.
[2020-03-03T21:41:46+01:00] DEBUG [tp:02d75d]: Failed to read packet error="transport is no longer being served"
[2020-03-03T21:41:46+01:00] WARN [tp_manager]: Failed to accept connection: dmsg error 200 - local entity closed
[2020-03-03T21:41:46+01:00] INFO [tp_manager]: transport manager closed.
[2020-03-03T21:41:46+01:00] INFO [tp:02d75d]: closed readPacket loop.
[2020-03-03T21:41:46+01:00] WARN [tp_manager]: failed to update transport statuses: transport not found
[2020-03-03T21:41:46+01:00] INFO [dmsg_client]: Session stopped. error=<nil>
[2020-03-03T21:41:46+01:00] INFO [dmsg_client]: Stopped serving client!
[2020-03-03T21:41:46+01:00] INFO [dmsg_client]: Session stopped. error=<nil>
[2020-03-03T21:41:46+01:00] INFO [dmsg_client]: Stopped serving client!
[2020-03-03T21:41:46+01:00] WARN [dmsg_client]: Stopped accepting streams. error="session shutdown" session=021584f99b9dc3dfa757a0760c93e0bf44b443dacb474376b90eec7d32a2092865
[2020-03-03T21:41:46+01:00] INFO [dmsg_server]: Stopping session... error="EOF" session=0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551
[2020-03-03T21:41:46+01:00] INFO [dmsg_client]: Session closed. error=<nil>
[2020-03-03T21:41:46+01:00] INFO [dmsg_client]: All sessions closed.
[2020-03-03T21:41:46+01:00] INFO [dmsg_server]: Stopped session. error=<nil> remote_pk=0345327088f0f34c359ecf67892fbe58a1cd7299e15a797339fa29365cc2e7c551 remote_tcp=127.0.0.1:55541
[2020-03-03T21:41:46+01:00] WARN [dmsg_client]: Stopped accepting streams. error="session shutdown" session=021584f99b9dc3dfa757a0760c93e0bf44b443dacb474376b90eec7d32a2092865
[2020-03-03T21:41:46+01:00] INFO [dmsg_server]: Stopping session... error="EOF" session=02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3
[2020-03-03T21:41:46+01:00] INFO [dmsg_client]: Stopped serving client!
[2020-03-03T21:41:46+01:00] INFO [dmsg_client]: Session stopped. error=<nil>
[2020-03-03T21:41:46+01:00] INFO [dmsg_client]: Session closed. error=<nil>
[2020-03-03T21:41:46+01:00] INFO [dmsg_client]: All sessions closed.
[2020-03-03T21:41:46+01:00] INFO [dmsg_server]: Stopped session. error=<nil> remote_pk=02d75d089b307032a3dfd1e6808f6a4ea0011205f60e7f28f69f444c4e48b2b7c3 remote_tcp=127.0.0.1:55548
[2020-03-03T21:41:46+01:00] INFO [dmsg_client]: Stopped serving client!
[2020-03-03T21:41:46+01:00] INFO [dmsg_server]: Stopped server. local_addr="" local_pk=021584f99b9dc3dfa757a0760c93e0bf44b443dacb474376b90eec7d32a2092865
[2020-03-03T21:41:46+01:00] INFO [dmsg_server]: Stopping server, net.Listener closed. error=<nil> local_addr="" local_pk=021584f99b9dc3dfa757a0760c93e0bf44b443dacb474376b90eec7d32a2092865
FAIL
coverage: 73.0% of statements
FAIL    github.com/SkycoinProject/skywire-mainnet/pkg/transport 59.227s

Steps to Reproduce
Steps to reproduce the behavior:

Sometimes it may be observed make check but I ran for i in {1..100}; do make check; done

@nkryuchkov nkryuchkov added bug Something isn't working milestone2 labels Mar 3, 2020
@nkryuchkov nkryuchkov self-assigned this Mar 3, 2020
@nkryuchkov nkryuchkov mentioned this issue Mar 4, 2020
Merged
@nkryuchkov nkryuchkov reopened this Mar 4, 2020
@nkryuchkov
Copy link
Contributor Author

Still happens.

@nkryuchkov nkryuchkov mentioned this issue Mar 5, 2020
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@nkryuchkov nkryuchkov

Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Fix SettlementHS test nkryuchkov/skywire
Fix SettlementHS test nkryuchkov/skywire
1 participant
@nkryuchkov