-
Notifications
You must be signed in to change notification settings - Fork 1.7k
Secret Store, Intermittent hung up on Key generation session #11141
Description
- Parity Ethereum version: 2.5.7
- Operating system: Linux (docker)
- Installation: built from source (with secret store)
- Fully synchronized: no
- Network: private / aura / secret store
- Restarted: yes
- Confguration: 3 nodes with aura consensus (docker compose)
Secret store frequently failed to generate server key session and just hung up (resulting in request timeout), need to restart all secret store nodes to recover
Expected Behaviour
Key generation success, if error occurred should return error message immediately and should not causing request timeout.
Actual
I rarely have successful request of key generation in 10 request sequentially, one hang up, I need to restart all secret store node to be able to get expected response from secret store. This issue is not occurred in ocean protocol fork (I'm using their docker images of parity fork with secret store - oceanprotocol/parity-ethereum:master)
Step to Reproduce
Invoke POST /shadow/[DOCUMENT_ID]/[SIGNED_DOCUMENT_ID]/1
Notes
This is not specific on key generation session, sometimes this happening on document key store request or document key retrieval. I suspect this is related to cluster communication / coordination
Configuration
parity]
chain = "/home/parity/chain.json"
[account]
password = ["/home/parity/password"]
[network]
reserved_peers = "/home/parity/reserved_peers"
[rpc]
interface = "0.0.0.0"
cors = ["all"]
hosts = ["all"]
apis = ["all"]
server_threads = 8
processing_threads = 0
[mining]
reseal_on_txs = "none"
engine_signer = "0x59f6566306843fb7d18f782733e19223ca5f07ab"
force_sealing = true
#reseal_max_period = 300000
tx_queue_no_early_reject = true
tx_queue_mem_limit = 0
tx_queue_per_sender = 8192
tx_queue_size = 32768
gas_floor_target = "40000000"
[websockets]
disable = false
port = 8546
interface = "all"
origins = ["http://127.0.0.1:8180"]
apis = ["all"]
hosts = ["all"]
[secretstore]
self_secret = "59f6566306843fb7d18f782733e19223ca5f07ab"
disable = false
disable_http = false # This node will expose a Secret Store HTTP API
http_interface = "all" # The HTTP API is available locally only
http_port = 8010 # The Secret Store HTTP API is available at this port
acl_contract = "289631594ec63a592aed277Ef6Dce46937959A7e" # Insecure, will be changed later on
#acl_contract = "none"
server_set_contract = "none"
nodes = ["40eadf91ffa4cae66491316f157604fd4ff68589143b74a7879f83b135e35ebceddb383adb62f0f2a29aab39cc9bd496f9fbbeda737a054e8c90d371d98689fd@10.1.0.101:8011","1fef86537f848e8fce58596aa24511f3a4b9df68919b4a2155e607132a8eb10c0c199d050faa36194325c000ed97ecd2c433e00712ca44e2b21393fb216e19be@10.1.0.102:8011","7aead779d8027d73a3f23378712945a01a88bd23bc32679017e7dcd2c670895e6f1710881b7c658b8d1af76c4d4cbc9fcdf86f32e9db062ea1799de16aa2bc8a@10.1.0.103:8011"]
interface = "all"
port = 8011 # port used to communicated with other Secret Store n0des
path = "/parity/config/secret/db.ss1"
[misc]
logging = "secretstore=trace,secretstore_net=trace"
Log
Node1 40eadf91ffa4cae66491316f157604fd4ff68589143b74a7879f83b135e35ebceddb383adb62f0f2a29aab39cc9bd496f9fbbeda737a054e8c90d371d98689fd
2019-10-08 06:01:32 UTC tokio-runtime-worker-2 TRACE secretstore_net 0x40ea…89fd: executing maintain procedures
2019-10-08 06:01:36 UTC tokio-runtime-worker-0 TRACE secretstore_net 0x40ea…89fd: sent message Generation.InitializeSession to 0x1fef…19be
2019-10-08 06:01:36 UTC tokio-runtime-worker-1 TRACE secretstore_net 0x40ea…89fd: received message Generation.ConfirmInitialization from 0x1fef…19be
2019-10-08 06:01:36 UTC tokio-runtime-worker-1 TRACE secretstore_net 0x40ea…89fd: sent message Generation.InitializeSession to 0x7aea…bc8a
2019-10-08 06:01:36 UTC tokio-runtime-worker-2 TRACE secretstore_net 0x40ea…89fd: received message Generation.ConfirmInitialization from 0x7aea…bc8a
2019-10-08 06:01:36 UTC tokio-runtime-worker-2 TRACE secretstore_net 0x40ea…89fd: sent message Generation.CompleteInitialization to 0x1fef…19be
2019-10-08 06:01:36 UTC tokio-runtime-worker-2 TRACE secretstore_net 0x40ea…89fd: sent message Generation.CompleteInitialization to 0x7aea…bc8a
2019-10-08 06:01:36 UTC tokio-runtime-worker-2 TRACE secretstore_net 0x40ea…89fd: sent message Generation.KeysDissemination to 0x1fef…19be
2019-10-08 06:01:36 UTC tokio-runtime-worker-2 TRACE secretstore_net 0x40ea…89fd: sent message Generation.KeysDissemination to 0x7aea…bc8a
2019-10-08 06:01:36 UTC tokio-runtime-worker-1 TRACE secretstore_net 0x40ea…89fd: received message Generation.KeysDissemination from 0x1fef…19be
2019-10-08 06:01:36 UTC tokio-runtime-worker-1 TRACE secretstore_net 0x40ea…89fd: received message Generation.PublicKeyShare from 0x1fef…19be
2019-10-08 06:01:42 UTC tokio-runtime-worker-1 TRACE secretstore_net 0x40ea…89fd: executing maintain procedures
2019-10-08 06:01:52 UTC tokio-runtime-worker-2 TRACE secretstore_net 0x40ea…89fd: executing maintain procedures
2019-10-08 06:01:57 UTC IO Worker #3 INFO import 2/25 peers 51 KiB chain 21 KiB db 0 bytes queue 3 KiB sync RPC: 3 conn, 0 req/s, 533 µs
2019-10-08 06:02:02 UTC tokio-runtime-worker-2 TRACE secretstore_net 0x40ea…89fd: executing maintain procedures
2019-10-08 06:02:12 UTC tokio-runtime-worker-1 TRACE secretstore_net 0x40ea…89fd: executing maintain procedures
2019-10-08 06:02:12 UTC tokio-runtime-worker-2 TRACE secretstore_net 0x40ea…89fd: received message Cluster.KeepAliveResponse from 0x1fef…19be
Node2 1fef86537f848e8fce58596aa24511f3a4b9df68919b4a2155e607132a8eb10c0c199d050faa36194325c000ed97ecd2c433e00712ca44e2b21393fb216e19be
2019-10-08 06:01:32 UTC tokio-runtime-worker-0 TRACE secretstore_net 0x1fef…19be: executing maintain procedures
2019-10-08 06:01:36 UTC tokio-runtime-worker-0 TRACE secretstore_net 0x1fef…19be: received message Generation.InitializeSession from 0x40ea…89fd
2019-10-08 06:01:36 UTC tokio-runtime-worker-0 TRACE secretstore_net 0x1fef…19be: sent message Generation.ConfirmInitialization to 0x40ea…89fd
2019-10-08 06:01:36 UTC tokio-runtime-worker-0 TRACE secretstore_net 0x1fef…19be: received message Generation.CompleteInitialization from 0x40ea…89fd
2019-10-08 06:01:36 UTC tokio-runtime-worker-0 TRACE secretstore_net 0x1fef…19be: sent message Generation.KeysDissemination to 0x40ea…89fd
2019-10-08 06:01:36 UTC tokio-runtime-worker-0 TRACE secretstore_net 0x1fef…19be: sent message Generation.KeysDissemination to 0x7aea…bc8a
2019-10-08 06:01:36 UTC tokio-runtime-worker-1 TRACE secretstore_net 0x1fef…19be: received message Generation.KeysDissemination from 0x40ea…89fd
2019-10-08 06:01:36 UTC tokio-runtime-worker-2 TRACE secretstore_net 0x1fef…19be: received message Generation.KeysDissemination from 0x7aea…bc8a
2019-10-08 06:01:36 UTC tokio-runtime-worker-2 TRACE secretstore_net 0x1fef…19be: sent message Generation.PublicKeyShare to 0x40ea…89fd
2019-10-08 06:01:36 UTC tokio-runtime-worker-2 TRACE secretstore_net 0x1fef…19be: sent message Generation.PublicKeyShare to 0x7aea…bc8a
2019-10-08 06:01:36 UTC tokio-runtime-worker-1 TRACE secretstore_net 0x1fef…19be: received message Generation.PublicKeyShare from 0x7aea…bc8a
2019-10-08 06:01:42 UTC tokio-runtime-worker-2 TRACE secretstore_net 0x1fef…19be: executing maintain procedures
2019-10-08 06:01:52 UTC tokio-runtime-worker-1 TRACE secretstore_net 0x1fef…19be: executing maintain procedures
2019-10-08 06:01:52 UTC IO Worker #2 INFO import 2/25 peers 17 KiB chain 18 KiB db 0 bytes queue 2 KiB sync RPC: 0 conn, 0 req/s, 0 µs
2019-10-08 06:02:02 UTC tokio-runtime-worker-0 TRACE secretstore_net 0x1fef…19be: executing maintain procedures
2019-10-08 06:02:12 UTC tokio-runtime-worker-2 TRACE secretstore_net 0x1fef…19be: received message Cluster.KeepAlive from 0x7aea…bc8a
2019-10-08 06:02:12 UTC tokio-runtime-worker-2 TRACE secretstore_net 0x1fef…19be: received message Cluster.KeepAlive from 0x40ea…89fd
2019-10-08 06:02:12 UTC tokio-runtime-worker-0 TRACE secretstore_net 0x1fef…19be: executing maintain procedures
2019-10-08 06:02:12 UTC tokio-runtime-worker-1 WARN secretstore_net 0x1fef…19be: network error 'early eof' when reading message from node 0x7aea…bc8a
2019-10-08 06:02:12 UTC tokio-runtime-worker-1 TRACE secretstore_net 0x1fef…19be: removing connection to 0x7aea…bc8a at 10.1.0.103:8011
2019-10-08 06:02:18 UTC IO Worker #1 INFO import Imported #9 0x9a64…19c9 (0 txs, 0.00 Mgas, 1 ms, 1.30 KiB)
2019-10-08 06:02:22 UTC tokio-runtime-worker-1 TRACE secretstore_net 0x1fef…19be: executing maintain procedures
2019-10-08 06:02:27 UTC tokio-runtime-worker-2 WARN secretstore_net 0x1fef…19be: timeout when establishing outbound connection with 10.1.0.103:8011
2019-10-08 06:02:27 UTC IO Worker #2 INFO import 1/25 peers 41 KiB chain 18 KiB db 0 bytes queue 2 KiB sync RPC: 0 conn, 0 req/s, 0 µs
2019-10-08 06:02:32 UTC tokio-runtime-worker-2 TRACE secretstore_net 0x1fef…19be: executing maintain procedures
2019-10-08 06:02:37 UTC tokio-runtime-worker-1 WARN secretstore_net 0x1fef…19be: timeout when establishing outbound connection with 10.1.0.103:8011
Node3 7aead779d8027d73a3f23378712945a01a88bd23bc32679017e7dcd2c670895e6f1710881b7c658b8d1af76c4d4cbc9fcdf86f32e9db062ea1799de16aa2bc8a
2019-10-08 06:01:32 UTC tokio-runtime-worker-2 TRACE secretstore_net 0x7aea…bc8a: executing maintain procedures
2019-10-08 06:01:32 UTC IO Worker #1 INFO import 2/25 peers 51 KiB chain 22 KiB db 0 bytes queue 2 KiB sync RPC: 0 conn, 0 req/s, 0 µs
2019-10-08 06:01:36 UTC tokio-runtime-worker-1 TRACE secretstore_net 0x7aea…bc8a: received message Generation.InitializeSession from 0x40ea…89fd
2019-10-08 06:01:36 UTC tokio-runtime-worker-1 TRACE secretstore_net 0x7aea…bc8a: sent message Generation.ConfirmInitialization to 0x40ea…89fd
2019-10-08 06:01:36 UTC tokio-runtime-worker-1 TRACE secretstore_net 0x7aea…bc8a: received message Generation.CompleteInitialization from 0x40ea…89fd
2019-10-08 06:01:36 UTC tokio-runtime-worker-0 TRACE secretstore_net 0x7aea…bc8a: received message Generation.KeysDissemination from 0x1fef…19be
2019-10-08 06:01:36 UTC tokio-runtime-worker-1 TRACE secretstore_net 0x7aea…bc8a: sent message Generation.KeysDissemination to 0x1fef…19be
2019-10-08 06:01:36 UTC tokio-runtime-worker-1 TRACE secretstore_net 0x7aea…bc8a: sent message Generation.KeysDissemination to 0x40ea…89fd
2019-10-08 06:01:36 UTC tokio-runtime-worker-0 TRACE secretstore_net 0x7aea…bc8a: received message Generation.KeysDissemination from 0x40ea…89fd
2019-10-08 06:01:36 UTC tokio-runtime-worker-0 TRACE secretstore_net 0x7aea…bc8a: sent message Generation.PublicKeyShare to 0x1fef…19be
2019-10-08 06:01:36 UTC tokio-runtime-worker-2 TRACE secretstore_net 0x7aea…bc8a: received message Generation.PublicKeyShare from 0x1fef…19be
2019-10-08 06:01:36 UTC tokio-runtime-worker-0 TRACE secretstore_net 0x7aea…bc8a: sent message Generation.PublicKeyShare to 0x40ea…89fd
2019-10-08 06:01:42 UTC tokio-runtime-worker-2 TRACE secretstore_net 0x7aea…bc8a: executing maintain procedures
2019-10-08 06:01:52 UTC tokio-runtime-worker-1 TRACE secretstore_net 0x7aea…bc8a: executing maintain procedures
2019-10-08 06:02:02 UTC tokio-runtime-worker-2 TRACE secretstore_net 0x7aea…bc8a: executing maintain procedures
2019-10-08 06:02:02 UTC IO Worker #2 INFO import 2/25 peers 51 KiB chain 22 KiB db 0 bytes queue 2 KiB sync RPC: 0 conn, 0 req/s, 0 µs
2019-10-08 06:02:12 UTC tokio-runtime-worker-2 TRACE secretstore_net 0x7aea…bc8a: executing maintain procedures
2019-10-08 06:02:12 UTC tokio-runtime-worker-0 TRACE secretstore_net 0x7aea…bc8a: received message Cluster.KeepAlive from 0x40ea…89fd
====================
stack backtrace:
0: 0x557cc09e2abd - <no info>
1: 0x557cc09dfdd2 - <no info>
2: 0x557cc0c89387 - <no info>
3: 0x557cc0a3d674 - <no info>
4: 0x557cc0a3d3ee - <no info>
5: 0x557cc0a3e755 - <no info>
6: 0x557cc0a4c43b - <no info>
7: 0x557cc0a4dd85 - <no info>
8: 0x557cbfa8b7f8 - <no info>
9: 0x557cc08d244f - <no info>
10: 0x557cc08d07d2 - <no info>
11: 0x557cc08cf160 - <no info>
12: 0x557cc08ba041 - <no info>
13: 0x557cc08d3b8b - <no info>
14: 0x557cc08d16c2 - <no info>
15: 0x557cc0a3baae - <no info>
16: 0x557cc0a3b98b - <no info>
17: 0x7f41818acbf0 - <no info>
Thread 'tokio-runtime-worker-2' panicked at 'supplied instant is later than self', src/libcore/option.rs:1034
This is a bug. Please report it at:
https://github.com/paritytech/parity-ethereum/issues/new
2019-10-08 06:02:12 UTC main INFO parity_ethereum::run Finishing work, please wait...
2019-10-08 06:02:12 UTC tokio-runtime-worker-1 TRACE secretstore_net 0x7aea…bc8a: received message Cluster.KeepAliveResponse from 0x1fef…19be
2019-10-08 06:02:12 UTC main WARN shutdown unable to get mut ref for engine for shutdown.