Skip to content

Instantly share code, notes, and snippets.

@seunlanlege
Created March 12, 2020 10:43
Show Gist options
  • Save seunlanlege/ac80b3732565d6af0c6519df3d2855d1 to your computer and use it in GitHub Desktop.
Save seunlanlege/ac80b3732565d6af0c6519df3d2855d1 to your computer and use it in GitHub Desktop.
substrate on  seun-remove-client-sc-network [$] via 𝗥 v1.41.0
➜ env RUST_LOG=trie=info,trace cargo test -p sc-network --lib protocol::light_client_handler::tests::send_receive_header
Finished test [unoptimized + debuginfo] target(s) in 0.86s
Running target/debug/deps/sc_network-bbd6be5835037894
running 1 test
[2020-03-12T10:29:24Z TRACE sc_state_db] StateDb settings: Constrained(Constraints { max_blocks: Some(4294967295), max_mem: None })
[2020-03-12T10:29:24Z TRACE sc_state_db] DB pruning mode: None
[2020-03-12T10:29:24Z TRACE sc_state_db::pruning] Reading pruning journal. Pending #0
[2020-03-12T10:29:24Z INFO sc_client::client] Initializing Genesis block/state (state: 0x360a…7800, header-hash: 0xa2ca…a899)
[2020-03-12T10:29:24Z TRACE sc_state_db::noncanonical] Inserted uncanonicalized changeset 0.0 (9 inserted, 0 deleted)
[2020-03-12T10:29:24Z TRACE sc_state_db::noncanonical] Canonicalizing 0xa2ca5de4a0d1c4f9cebd7c6913fa1f3233b2edf07f868bc53b6ed7a8c8cea899
[2020-03-12T10:29:24Z TRACE sc_state_db::noncanonical] Discarding 1 records
[2020-03-12T10:29:24Z TRACE sc_state_db::pruning] Adding to pruning window: 0xa2ca5de4a0d1c4f9cebd7c6913fa1f3233b2edf07f868bc53b6ed7a8c8cea899 (9 inserted, 0 deleted)
[2020-03-12T10:29:24Z DEBUG sc_client_db] DB Commit 0xa2ca5de4a0d1c4f9cebd7c6913fa1f3233b2edf07f868bc53b6ed7a8c8cea899 (0), best = true
[2020-03-12T10:29:24Z TRACE sc_client_db::storage_cache] Syncing cache, id = (#Some(0), Some(0xa2ca5de4a0d1c4f9cebd7c6913fa1f3233b2edf07f868bc53b6ed7a8c8cea899)), parent=None, best=true
[2020-03-12T10:29:24Z TRACE sc_client_db::storage_cache] Syncing shared cache, enacted = [], retracted = []
[2020-03-12T10:29:24Z TRACE sc_state_db::noncanonical] Post canonicalizing 0xa2ca5de4a0d1c4f9cebd7c6913fa1f3233b2edf07f868bc53b6ed7a8c8cea899
[2020-03-12T10:29:24Z TRACE sc_state_db] First available: Some(0xa2ca5de4a0d1c4f9cebd7c6913fa1f3233b2edf07f868bc53b6ed7a8c8cea899) (0), Last canon: Some(0xa2ca5de4a0d1c4f9cebd7c6913fa1f3233b2edf07f868bc53b6ed7a8c8cea899) (0), Best forks: []
[2020-03-12T10:29:24Z TRACE sc_state_db] StateDb settings: Constrained(Constraints { max_blocks: Some(4294967295), max_mem: None })
[2020-03-12T10:29:24Z TRACE sc_state_db] DB pruning mode: None
[2020-03-12T10:29:24Z TRACE sc_state_db::pruning] Reading pruning journal. Pending #0
[2020-03-12T10:29:24Z INFO sc_client::client] Initializing Genesis block/state (state: 0x360a…7800, header-hash: 0xa2ca…a899)
[2020-03-12T10:29:24Z TRACE sc_state_db::noncanonical] Inserted uncanonicalized changeset 0.0 (9 inserted, 0 deleted)
[2020-03-12T10:29:24Z TRACE sc_state_db::noncanonical] Canonicalizing 0xa2ca5de4a0d1c4f9cebd7c6913fa1f3233b2edf07f868bc53b6ed7a8c8cea899
[2020-03-12T10:29:24Z TRACE sc_state_db::noncanonical] Discarding 1 records
[2020-03-12T10:29:24Z TRACE sc_state_db::pruning] Adding to pruning window: 0xa2ca5de4a0d1c4f9cebd7c6913fa1f3233b2edf07f868bc53b6ed7a8c8cea899 (9 inserted, 0 deleted)
[2020-03-12T10:29:24Z DEBUG sc_client_db] DB Commit 0xa2ca5de4a0d1c4f9cebd7c6913fa1f3233b2edf07f868bc53b6ed7a8c8cea899 (0), best = true
[2020-03-12T10:29:24Z TRACE sc_client_db::storage_cache] Syncing cache, id = (#Some(0), Some(0xa2ca5de4a0d1c4f9cebd7c6913fa1f3233b2edf07f868bc53b6ed7a8c8cea899)), parent=None, best=true
[2020-03-12T10:29:24Z TRACE sc_client_db::storage_cache] Syncing shared cache, enacted = [], retracted = []
[2020-03-12T10:29:24Z TRACE sc_state_db::noncanonical] Post canonicalizing 0xa2ca5de4a0d1c4f9cebd7c6913fa1f3233b2edf07f868bc53b6ed7a8c8cea899
[2020-03-12T10:29:24Z TRACE sc_state_db] First available: Some(0xa2ca5de4a0d1c4f9cebd7c6913fa1f3233b2edf07f868bc53b6ed7a8c8cea899) (0), Last canon: Some(0xa2ca5de4a0d1c4f9cebd7c6913fa1f3233b2edf07f868bc53b6ed7a8c8cea899) (0), Best forks: []
[2020-03-12T10:29:24Z INFO async_std::task::builder] spawn
[2020-03-12T10:29:24Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /noise/xx/25519/chachapoly/sha256/0.1.0
[2020-03-12T10:29:24Z INFO async_std::task::block_on] block_on
[2020-03-12T10:29:24Z DEBUG sc_network::protocol::light_client_handler] no peer available to send request to
[2020-03-12T10:29:24Z TRACE multistream_select::protocol] Received message: Header(V1)
[2020-03-12T10:29:24Z TRACE multistream_select::protocol] Received message: Protocol(Protocol(b"/noise/xx/25519/chachapoly/sha256/0.1.0"))
[2020-03-12T10:29:24Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /noise/xx/25519/chachapoly/sha256/0.1.0
[2020-03-12T10:29:24Z TRACE multistream_select::protocol] Received message: Header(V1)
[2020-03-12T10:29:24Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /noise/xx/25519/chachapoly/sha256/0.1.0
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: Init
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE multistream_select::protocol] Received message: Protocol(Protocol(b"/noise/xx/25519/chachapoly/sha256/0.1.0"))
[2020-03-12T10:29:24Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /noise/xx/25519/chachapoly/sha256/0.1.0
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: Init
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: BufferData { off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write: buffered 0 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: encrypting 0 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: cipher text len = 32 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: writing len (32, [0, 32], 0/2)
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: wrote 32/32 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: finished writing 32 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: Init
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: next frame len = 32
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadData { len: 32, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: read 32/32 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: decrypting 32 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: payload len = 0 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: CopyData { len: 0, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: copied 0/0 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: Init
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: BufferData { off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write: buffered 2 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: BufferData { off: 2 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write: buffered 106 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: encrypting 106 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: cipher text len = 202 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: writing len (202, [0, 202], 0/2)
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: wrote 202/202 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: finished writing 202 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: next frame len = 202
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadData { len: 202, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: read 202/202 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: decrypting 202 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: payload len = 106 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: CopyData { len: 106, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: copied 2/106 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: CopyData { len: 106, off: 2 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: copied 106/106 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: Init
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: BufferData { off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write: buffered 2 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: BufferData { off: 2 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write: buffered 106 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: encrypting 106 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: cipher text len = 170 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: writing len (170, [0, 170], 0/2)
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: wrote 170/170 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: finished writing 170 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: next frame len = 170
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadData { len: 170, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: read 170/170 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: decrypting 170 bytes
[2020-03-12T10:29:24Z DEBUG libp2p_core::upgrade::apply] Successfully applied negotiated protocol
[2020-03-12T10:29:24Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /yamux/1.0.0
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: Init
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: BufferData { off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write: buffered 34 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: encrypting 34 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: payload len = 106 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: cipher text len = 50 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: CopyData { len: 106, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: writing len (50, [0, 50], 0/2)
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: copied 2/106 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: CopyData { len: 106, off: 2 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: wrote 50/50 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: copied 106/106 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: finished writing 50 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z DEBUG libp2p_core::upgrade::apply] Successfully applied negotiated protocol
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: next frame len = 50
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadData { len: 50, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: read 50/50 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: decrypting 50 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: payload len = 34 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: CopyData { len: 34, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: copied 1/34 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: CopyData { len: 34, off: 1 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: copied 20/34 bytes
[2020-03-12T10:29:24Z TRACE multistream_select::protocol] Received message: Header(V1)
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: Init
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: BufferData { off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write: buffered 20 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: encrypting 20 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: cipher text len = 36 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: writing len (36, [0, 36], 0/2)
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: wrote 36/36 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: finished writing 36 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: CopyData { len: 34, off: 20 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: copied 21/34 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: CopyData { len: 34, off: 21 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: copied 34/34 bytes
[2020-03-12T10:29:24Z TRACE multistream_select::protocol] Received message: Protocol(Protocol(b"/yamux/1.0.0"))
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /yamux/1.0.0
[2020-03-12T10:29:24Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /yamux/1.0.0
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: next frame len = 36
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadData { len: 36, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: read 36/36 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: decrypting 36 bytes
[2020-03-12T10:29:24Z DEBUG yamux::connection] new connection: ae7bc1bc (Server)
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: payload len = 20 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: CopyData { len: 20, off: 0 }
[2020-03-12T10:29:24Z DEBUG libp2p_core::upgrade::apply] Successfully applied negotiated protocol
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: copied 1/20 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: CopyData { len: 20, off: 1 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: copied 20/20 bytes
[2020-03-12T10:29:24Z TRACE multistream_select::protocol] Received message: Header(V1)
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: Init
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: BufferData { off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write: buffered 14 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: encrypting 14 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: cipher text len = 30 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: writing len (30, [0, 30], 0/2)
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: wrote 30/30 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: finished writing 30 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE sc_network::protocol::light_client_handler] peer QmckW4RjFKZwR5ExnnR7sxbmKgYyJdS5F93okrSa4W1qH1 connected with address /memory/5428832177287198677
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: next frame len = 30
[2020-03-12T10:29:24Z DEBUG sc_network::protocol::light_client_handler] no peer available to send request to
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadData { len: 30, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: read 30/30 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: decrypting 30 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: payload len = 14 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: CopyData { len: 14, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: copied 1/14 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: CopyData { len: 14, off: 1 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: copied 14/14 bytes
[2020-03-12T10:29:24Z TRACE multistream_select::protocol] Received message: Protocol(Protocol(b"/yamux/1.0.0"))
[2020-03-12T10:29:24Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /yamux/1.0.0
[2020-03-12T10:29:24Z DEBUG yamux::connection] new connection: 8648dc10 (Client)
[2020-03-12T10:29:24Z DEBUG libp2p_core::upgrade::apply] Successfully applied negotiated protocol
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE sc_network::protocol::light_client_handler] peer QmVB6AVyg5zkiF6a5vTxduqGHCc8RGPvk7Z9BF9FE4f5tm connected with address /memory/5428832177287198677
[2020-03-12T10:29:24Z TRACE sc_network::protocol::light_client_handler] sending request 1 to peer QmVB6AVyg5zkiF6a5vTxduqGHCc8RGPvk7Z9BF9FE4f5tm
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE yamux::connection] 8648dc10: creating new outbound stream
[2020-03-12T10:29:24Z TRACE yamux::connection] 8648dc10: sending initial (Header WindowUpdate 1 (len 262144) (flags 1))
[2020-03-12T10:29:24Z DEBUG yamux::connection] 8648dc10: new outbound (Stream 8648dc10/1) of (Connection 8648dc10 Client (streams 0))
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: Init
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: BufferData { off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write: buffered 12 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: encrypting 12 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: cipher text len = 28 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: writing len (28, [0, 28], 0/2)
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: wrote 28/28 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: finished writing 28 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: next frame len = 28
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadData { len: 28, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: read 28/28 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: decrypting 28 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: payload len = 12 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: CopyData { len: 12, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: copied 12/12 bytes
[2020-03-12T10:29:24Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /foo/light/2
[2020-03-12T10:29:24Z TRACE yamux::connection] ae7bc1bc: received: (Header WindowUpdate 1 (len 262144) (flags 1))
[2020-03-12T10:29:24Z TRACE yamux::connection::stream] 8648dc10/1: write 34 bytes
[2020-03-12T10:29:24Z TRACE yamux::connection] ae7bc1bc: new inbound (Stream ae7bc1bc/1) of (Connection ae7bc1bc Server (streams 1))
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE yamux::connection] 8648dc10: sending: (Header Data 1 (len 34) (flags 0))
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: Init
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: BufferData { off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write: buffered 46 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: encrypting 46 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: cipher text len = 62 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: writing len (62, [0, 62], 0/2)
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: wrote 62/62 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: finished writing 62 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: next frame len = 62
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadData { len: 62, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: read 62/62 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: decrypting 62 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: payload len = 46 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: CopyData { len: 46, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: copied 46/46 bytes
[2020-03-12T10:29:24Z TRACE yamux::connection] ae7bc1bc: received: (Header Data 1 (len 34) (flags 0))
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE yamux::connection::stream] ae7bc1bc/1: read 1 bytes
[2020-03-12T10:29:24Z TRACE yamux::connection::stream] ae7bc1bc/1: read 19 bytes
[2020-03-12T10:29:24Z TRACE multistream_select::protocol] Received message: Header(V1)
[2020-03-12T10:29:24Z TRACE yamux::connection::stream] ae7bc1bc/1: write 20 bytes
[2020-03-12T10:29:24Z TRACE yamux::connection::stream] ae7bc1bc/1: read 1 bytes
[2020-03-12T10:29:24Z TRACE yamux::connection::stream] ae7bc1bc/1: read 13 bytes
[2020-03-12T10:29:24Z TRACE multistream_select::protocol] Received message: Protocol(Protocol(b"/foo/light/2"))
[2020-03-12T10:29:24Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /foo/light/2
[2020-03-12T10:29:24Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /foo/light/2
[2020-03-12T10:29:24Z TRACE yamux::connection::stream] ae7bc1bc/1: write 14 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE yamux::connection] ae7bc1bc: sending: (Header Data 1 (len 20) (flags 2))
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: Init
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: BufferData { off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write: buffered 32 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: encrypting 32 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: cipher text len = 48 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: writing len (48, [0, 48], 0/2)
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: wrote 48/48 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: finished writing 48 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE yamux::connection] ae7bc1bc: sending: (Header Data 1 (len 14) (flags 0))
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: Init
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: BufferData { off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: next frame len = 48
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write: buffered 26 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadData { len: 48, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: encrypting 26 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: read 48/48 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: cipher text len = 42 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: decrypting 48 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: writing len (42, [0, 42], 0/2)
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: payload len = 32 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: CopyData { len: 32, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: wrote 42/42 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: copied 32/32 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: finished writing 42 bytes
[2020-03-12T10:29:24Z TRACE yamux::connection] 8648dc10: received: (Header Data 1 (len 20) (flags 2))
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: next frame len = 42
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadData { len: 42, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: read 42/42 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: decrypting 42 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: payload len = 26 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: CopyData { len: 26, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: copied 26/26 bytes
[2020-03-12T10:29:24Z TRACE yamux::connection] 8648dc10: received: (Header Data 1 (len 14) (flags 0))
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE yamux::connection::stream] 8648dc10/1: read 1 bytes
[2020-03-12T10:29:24Z TRACE yamux::connection::stream] 8648dc10/1: read 19 bytes
[2020-03-12T10:29:24Z TRACE multistream_select::protocol] Received message: Header(V1)
[2020-03-12T10:29:24Z TRACE yamux::connection::stream] 8648dc10/1: read 1 bytes
[2020-03-12T10:29:24Z TRACE yamux::connection::stream] 8648dc10/1: read 13 bytes
[2020-03-12T10:29:24Z TRACE multistream_select::protocol] Received message: Protocol(Protocol(b"/foo/light/2"))
[2020-03-12T10:29:24Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /foo/light/2
[2020-03-12T10:29:24Z TRACE yamux::connection::stream] 8648dc10/1: write 1 bytes
[2020-03-12T10:29:24Z TRACE yamux::connection::stream] 8648dc10/1: write 12 bytes
[2020-03-12T10:29:24Z TRACE yamux::connection::stream] 8648dc10/1: close
[2020-03-12T10:29:24Z TRACE yamux::connection::stream] 8648dc10/1: update state: (Open SendClosed SendClosed)
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE yamux::connection] 8648dc10: sending: (Header Data 1 (len 1) (flags 0))
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: Init
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: BufferData { off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write: buffered 13 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: encrypting 13 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: cipher text len = 29 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: writing len (29, [0, 29], 0/2)
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: wrote 29/29 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: finished writing 29 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE yamux::connection] 8648dc10: sending: (Header Data 1 (len 12) (flags 0))
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: Init
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: BufferData { off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: next frame len = 29
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write: buffered 24 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadData { len: 29, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: encrypting 24 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: cipher text len = 40 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: read 29/29 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: writing len (40, [0, 40], 0/2)
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: decrypting 29 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: wrote 40/40 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: payload len = 13 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: finished writing 40 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: CopyData { len: 13, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: copied 13/13 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE yamux::connection] ae7bc1bc: received: (Header Data 1 (len 1) (flags 0))
[2020-03-12T10:29:24Z TRACE yamux::connection] 8648dc10: closing stream 1 of (Connection 8648dc10 Client (streams 1))
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: Init
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write state: BufferData { off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] write: buffered 12 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: encrypting 12 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: cipher text len = 28 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: next frame len = 40
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: writing len (28, [0, 28], 0/2)
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadData { len: 40, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: wrote 28/28 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] flush: finished writing 28 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: read 40/40 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: decrypting 40 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: payload len = 24 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: CopyData { len: 24, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: copied 24/24 bytes
[2020-03-12T10:29:24Z TRACE yamux::connection] ae7bc1bc: received: (Header Data 1 (len 12) (flags 0))
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: next frame len = 28
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadData { len: 28, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: read 28/28 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: decrypting 28 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: payload len = 12 bytes
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: CopyData { len: 12, off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read: copied 12/12 bytes
[2020-03-12T10:29:24Z TRACE yamux::connection] ae7bc1bc: received: (Header Data 1 (len 0) (flags 4))
[2020-03-12T10:29:24Z TRACE yamux::connection::stream] ae7bc1bc/1: update state: (Open RecvClosed RecvClosed)
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE yamux::connection::stream] ae7bc1bc/1: read 1 bytes
[2020-03-12T10:29:24Z TRACE yamux::connection::stream] ae7bc1bc/1: read 12 bytes
[2020-03-12T10:29:24Z DEBUG libp2p_core::upgrade::apply] Successfully applied negotiated protocol
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:24Z TRACE sc_network::protocol::light_client_handler] incoming request from QmckW4RjFKZwR5ExnnR7sxbmKgYyJdS5F93okrSa4W1qH1
[2020-03-12T10:29:24Z TRACE sc_network::protocol::light_client_handler] remote header proof request from QmckW4RjFKZwR5ExnnR7sxbmKgYyJdS5F93okrSa4W1qH1 ([1, 0, 0, 0, 0, 0, 0, 0])
[2020-03-12T10:29:24Z DEBUG sc_network::protocol::light_client_handler] error handling request from peer QmckW4RjFKZwR5ExnnR7sxbmKgYyJdS5F93okrSa4W1qH1: codec error: Not enough data to fill buffer
[2020-03-12T10:29:34Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:34Z TRACE yamux::connection::stream] 8648dc10/1: update state: (SendClosed Closed Closed)
[2020-03-12T10:29:34Z TRACE libp2p_noise::io] read state: ReadLen { buf: [0, 0], off: 0 }
[2020-03-12T10:29:34Z ERROR yamux::connection] ae7bc1bc: socket error: decode error: i/o error: broken pipe
[2020-03-12T10:29:34Z TRACE yamux::connection::stream] ae7bc1bc/1: update state: (RecvClosed Closed Closed)
[2020-03-12T10:29:34Z TRACE libp2p_swarm] Connection PeerId("QmVB6AVyg5zkiF6a5vTxduqGHCc8RGPvk7Z9BF9FE4f5tm") with endpoint Dialer { address: "/memory/5428832177287198677" } closed by Handler(Handler(Timeout))
[2020-03-12T10:29:34Z TRACE sc_network::protocol::light_client_handler] peer QmVB6AVyg5zkiF6a5vTxduqGHCc8RGPvk7Z9BF9FE4f5tm disconnected
[2020-03-12T10:29:34Z DEBUG sc_network::protocol::light_client_handler] no peer available to send request to
[2020-03-12T10:29:34Z TRACE libp2p_swarm] Connection PeerId("QmckW4RjFKZwR5ExnnR7sxbmKgYyJdS5F93okrSa4W1qH1") with endpoint Listener { local_addr: "/memory/5428832177287198677", send_back_addr: "/memory/5428832177287198677" } closed by Node(Custom { kind: Other, error: "yamux error: decode error: i/o error: broken pipe" })
[2020-03-12T10:29:34Z TRACE sc_network::protocol::light_client_handler] peer QmckW4RjFKZwR5ExnnR7sxbmKgYyJdS5F93okrSa4W1qH1 disconnected
[2020-03-12T10:29:34Z DEBUG sc_network::protocol::light_client_handler] no peer available to send request to
test protocol::light_client_handler::tests::send_receive_header ... test protocol::light_client_handler::tests::send_receive_header has been running for over 60 seconds
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment