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

worker fails to sync properly after runtime V6 update #42

Closed
brenzi opened this issue Dec 24, 2020 · 3 comments
Closed

worker fails to sync properly after runtime V6 update #42

brenzi opened this issue Dec 24, 2020 · 3 comments
Labels
bug Something isn't working wontfix This will not be worked on

Comments

@brenzi
Copy link
Member

brenzi commented Dec 24, 2020

After updating node and worker from 0.6.15 to 0.7.0 (breaking changes in substrate, different types) the worker doesn't synch properly but reports trouble with grandpa proofs:

Dec 24 14:53:37 devsgx03 encointer-worker[29010]: Chain Relay is synced until block: 627664
Dec 24 14:53:37 devsgx03 encointer-worker[29010]: Last finalized block number: 630628
Dec 24 14:53:37 devsgx03 encointer-worker[29010]: Remaining blocks to fetch until last synced header: 2336
Dec 24 14:53:37 devsgx03 encointer-worker[29010]: Remaining blocks to fetch until last synced header: 1336
Dec 24 14:53:37 devsgx03 encointer-worker[29010]: Remaining blocks to fetch until last synced header: 336
Dec 24 14:53:38 devsgx03 encointer-worker[29010]: [2020-12-24T13:53:38Z DEBUG chain_relay] Syncing finalized block without grandpa proof. Amount of unjustified headers: 465
Dec 24 14:53:45 devsgx03 encointer-worker[29010]: [2020-12-24T13:53:45Z DEBUG chain_relay] Syncing finalized block without grandpa proof. Amount of unjustified headers: 466
Dec 24 14:53:51 devsgx03 encointer-worker[29010]: [2020-12-24T13:53:51Z DEBUG chain_relay] Syncing finalized block without grandpa proof. Amount of unjustified headers: 467
Dec 24 14:53:58 devsgx03 encointer-worker[29010]: [2020-12-24T13:53:58Z DEBUG chain_relay] Syncing finalized block without grandpa proof. Amount of unjustified headers: 468
[....]
Dec 24 14:57:07 devsgx03 encointer-worker[29010]: [2020-12-24T13:57:07Z WARN  sp_io::storage] storage::clear_prefix() unimplemented
Dec 24 14:57:07 devsgx03 encointer-worker[29010]: [2020-12-24T13:57:07Z WARN  sp_io::storage] storage::clear_prefix() unimplemented
Dec 24 14:57:07 devsgx03 encointer-worker[29010]: [2020-12-24T13:57:07Z WARN  sp_io::storage] storage::clear_prefix() unimplemented
Dec 24 14:57:07 devsgx03 encointer-worker[29010]: [2020-12-24T13:57:07Z WARN  sp_io::storage] storage::clear_prefix() unimplemented
Dec 24 14:57:07 devsgx03 encointer-worker[29010]: [2020-12-24T13:57:07Z DEBUG pallet_encointer_ceremonies] purged registry for ceremony 2093
Dec 24 14:57:08 devsgx03 encointer-worker[29010]: [2020-12-24T13:57:08Z DEBUG chain_relay] Syncing finalized block without grandpa proof. Amount of unjustified headers: 497
Dec 24 14:57:15 devsgx03 encointer-worker[29010]: [2020-12-24T13:57:15Z DEBUG chain_relay] Syncing finalized block without grandpa proof. Amount of unjustified headers: 498
Dec 24 14:57:21 devsgx03 encointer-worker[29010]: [2020-12-24T13:57:21Z DEBUG chain_relay] Syncing finalized block without grandpa proof. Amount of unjustified headers: 499
Dec 24 14:57:28 devsgx03 encointer-worker[29010]: [2020-12-24T13:57:28Z DEBUG chain_relay] Syncing finalized block without grandpa proof. Amount of unjustified headers: 500
Dec 24 14:57:34 devsgx03 encointer-worker[29010]: [2020-12-24T13:57:34Z DEBUG chain_relay] Syncing finalized block without grandpa proof. Amount of unjustified headers: 501
Dec 24 14:57:41 devsgx03 encointer-worker[29010]: [2020-12-24T13:57:41Z DEBUG chain_relay] Syncing finalized block without grandpa proof. Amount of unjustified headers: 502
Dec 24 14:57:47 devsgx03 encointer-worker[29010]: [2020-12-24T13:57:47Z DEBUG chain_relay] Syncing finalized block without grandpa proof. Amount of unjustified headers: 503
Dec 24 14:57:54 devsgx03 encointer-worker[29010]: [2020-12-24T13:57:54Z DEBUG chain_relay] Syncing finalized block without grandpa proof. Amount of unjustified headers: 504
Dec 24 14:58:00 devsgx03 encointer-worker[29010]: [2020-12-24T13:58:00Z DEBUG chain_relay] Syncing finalized block without grandpa proof. Amount of unjustified headers: 505
Dec 24 14:58:07 devsgx03 encointer-worker[29010]: [2020-12-24T13:58:07Z DEBUG chain_relay] Syncing finalized block without grandpa proof. Amount of unjustified headers: 506
Dec 24 14:58:13 devsgx03 encointer-worker[29010]: [2020-12-24T13:58:13Z DEBUG chain_relay] Syncing finalized block without grandpa proof. Amount of unjustified headers: 507
Dec 24 14:58:20 devsgx03 encointer-worker[29010]: [2020-12-24T13:58:20Z DEBUG chain_relay] Syncing finalized block without grandpa proof. Amount of unjustified headers: 508
Dec 24 14:58:26 devsgx03 encointer-worker[29010]: [2020-12-24T13:58:26Z DEBUG chain_relay] Syncing finalized block without grandpa proof. Amount of unjustified headers: 509
Dec 24 14:58:33 devsgx03 encointer-worker[29010]: [2020-12-24T13:58:33Z DEBUG chain_relay] Syncing finalized block without grandpa proof. Amount of unjustified headers: 510
Dec 24 14:58:39 devsgx03 encointer-worker[29010]: [2020-12-24T13:58:39Z DEBUG chain_relay] Syncing finalized block without grandpa proof. Amount of unjustified headers: 511
Dec 24 14:58:53 devsgx03 encointer-worker[29010]: [2020-12-24T13:58:53Z DEBUG chain_relay] Syncing finalized block without grandpa proof. Amount of unjustified headers: 1
Dec 24 14:58:59 devsgx03 encointer-worker[29010]: [2020-12-24T13:58:59Z DEBUG chain_relay] Syncing finalized block without grandpa proof. Amount of unjustified headers: 2
Dec 24 14:59:05 devsgx03 encointer-worker[29010]: [2020-12-24T13:59:05Z DEBUG chain_relay] Syncing finalized block without grandpa proof. Amount of unjustified headers: 3
Dec 24 14:59:12 devsgx03 encointer-worker[29010]: [2020-12-24T13:59:12Z DEBUG chain_relay] Syncing finalized block without grandpa proof. Amount of unjustified headers: 4

And the worker-api is not responsive:

./encointer-client-teeproxy-0.7.0 -u wss://cantillon.encointer.org -p 443 -U wss://substratee03.scs.ch -P 443 trusted info --mrenclave $MRENCLAVE --shard $cid
Public information about currency ARhC6n8nE4wgeMtDtmapfFR4VctJNE6J2YPphJhRTrNq
[2020-12-24T13:59:45Z ERROR substratee_worker_api] [-] [WorkerApi]: error while handling request, returning
thread 'main' panicked at 'getting value from worker API failed: ()', client/src/main.rs:520:10
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
@brenzi brenzi changed the title worker fails to sync properly worker fails to sync properly after runtime V6 update Dec 24, 2020
@brenzi brenzi added the bug Something isn't working label Dec 25, 2020
@brenzi
Copy link
Member Author

brenzi commented Jan 5, 2021 •
edited
Loading

When trying to resynch the chain-relay, the follwoing happens:

enclave: 0.7.0
worker: 0.7.0
node-teeproxy 0.3.8
Cantillon chain runtime V6

Jan 05 17:51:53 devsgx03 encointer-worker[6408]: Remaining blocks to fetch until last synced header: 430000
Jan 05 17:51:53 devsgx03 encointer-worker[6408]: thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: Error("Decode error: No such variant in enum MultiAddress", line: 1, column: 911806)', /home/abrenzikofer/.c
Jan 05 17:51:53 devsgx03 encointer-worker[6408]: note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
Jan 05 17:52:04 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:04Z INFO  encointer_worker] Interacting with node on ws://127.0.0.1:19943
Jan 05 17:52:04 devsgx03 encointer-worker[17149]: *** Starting substraTEE-worker
Jan 05 17:52:04 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:04Z INFO  encointer_worker::enclave::api] [+] Home dir is /home/devsgxadmin
Jan 05 17:52:04 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:04Z INFO  encointer_worker::enclave::api] [-] Token file /home/devsgxadmin/../bin/enclave.token not found! Will create one.
Jan 05 17:52:08 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:08Z INFO  substratee_worker_enclave] [Enclave initialized] Ed25519 prim raw : [137, 179, 92, 254, 39, 54, 239, 120, 59, 225, 159, 136, 238, 208, 20, 14, 44, 10,
Jan 05 17:52:08 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:08Z INFO  encointer_worker] no shard specified. using mrenclave as id: CbE3fPWjeYVo9LSNKgPPiCXThFBjfhP1GK6Y9S7t5WVe
Jan 05 17:52:08 devsgx03 encointer-worker[17149]: Advertising worker api at wss://substratee03.scs.ch
Jan 05 17:52:08 devsgx03 encointer-worker[17149]: Encointer Worker v0.7.0
Jan 05 17:52:08 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:08Z INFO  encointer_worker] starting worker on shard CbE3fPWjeYVo9LSNKgPPiCXThFBjfhP1GK6Y9S7t5WVe
Jan 05 17:52:08 devsgx03 encointer-worker[17149]: *** Starting enclave in development mode
Jan 05 17:52:08 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:08Z INFO  encointer_worker::enclave::api] [+] Home dir is /home/devsgxadmin
Jan 05 17:52:08 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:08Z INFO  encointer_worker::enclave::api] [-] Token file /home/devsgxadmin/../bin/enclave.token not found! Will create one.
Jan 05 17:52:12 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:12Z INFO  substratee_worker_enclave] [Enclave initialized] Ed25519 prim raw : [137, 179, 92, 254, 39, 54, 239, 120, 59, 225, 159, 136, 238, 208, 20, 14, 44, 10,
Jan 05 17:52:12 devsgx03 encointer-worker[17149]: MRENCLAVE=CbE3fPWjeYVo9LSNKgPPiCXThFBjfhP1GK6Y9S7t5WVe
Jan 05 17:52:12 devsgx03 encointer-worker[17149]: worker api listening on ws://0.0.0.0:19944
Jan 05 17:52:12 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:12Z INFO  encointer_worker::ws_server] Starting WebSocket server on 0.0.0.0:19944
Jan 05 17:52:12 devsgx03 encointer-worker[17149]: MU-RA server listening on ws://0.0.0.0:19942
Jan 05 17:52:12 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:12Z INFO  encointer_worker::enclave::tls_ra] Starting MU-RA-Server on: 0.0.0.0:19942
Jan 05 17:52:12 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:12Z INFO  encointer_worker] encoding Alice's public         = [212, 53, 147, 199, 21, 253, 211, 28, 97, 20, 26, 189, 4, 169, 159, 214, 130, 44, 133, 88, 133, 76,
Jan 05 17:52:12 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:12Z INFO  encointer_worker] encoding Alice's AccountId = [212, 53, 147, 199, 21, 253, 211, 28, 97, 20, 26, 189, 4, 169, 159, 214, 130, 44, 133, 88, 133, 76, 205,
Jan 05 17:52:12 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:12Z INFO  encointer_worker]     Alice's free balance = 98650874962777
Jan 05 17:52:12 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:12Z INFO  encointer_worker]     Alice's Account Nonce is 289
Jan 05 17:52:12 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:12Z INFO  encointer_worker] TEE's free balance = 1000000000000
Jan 05 17:52:12 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:12Z INFO  encointer_worker] Enclave nonce = 3412
Jan 05 17:52:12 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:12Z INFO  substratee_worker_enclave::attestation] [Enclave Attestation] Ed25519 pub raw : [137, 179, 92, 254, 39, 54, 239, 120, 59, 225, 159, 136, 238, 208, 20,
Jan 05 17:52:12 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:12Z INFO  substratee_worker_enclave::attestation]     [Enclave] Generate keypair
Jan 05 17:52:12 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:12Z INFO  substratee_worker_enclave::attestation]     [Enclave] Generate ephemeral ECDSA keypair successful
Jan 05 17:52:12 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:12Z INFO  substratee_worker_enclave::attestation]     [Enclave] Create attestation report
Jan 05 17:52:12 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:12Z INFO  substratee_worker_enclave::attestation]     [Enclave] ias_sock = 7
Jan 05 17:52:13 devsgx03 encointer-worker[17149]:     [Enclave] Create attestation report successful
Jan 05 17:52:13 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:13Z INFO  substratee_worker_enclave::attestation]     [Enclave] Generate ECC Certificate
Jan 05 17:52:13 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:13Z INFO  substratee_worker_enclave::attestation]     [Enclave] Generate ECC Certificate successful
Jan 05 17:52:13 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:13Z INFO  substratee_worker_enclave::attestation]     [Enclave] Compose extrinsic
Jan 05 17:52:13 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:13Z INFO  substratee_worker_enclave::attestation] [Enclave] Restored ECC pubkey:
Jan 05 17:52:13 devsgx03 encointer-worker[17149]: [>] Register the enclave (send the extrinsic)
Jan 05 17:52:18 devsgx03 encointer-worker[17149]: [<] Extrinsic got finalized. Hash: Some(0x14ddc4cecc3c2ed550211d68f887b1bc7d908d980cacdac01cc69ae337e7bf61)
Jan 05 17:52:18 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:18Z INFO  encointer_worker] Got genesis Header:
Jan 05 17:52:18 devsgx03 encointer-worker[17149]:      Header { parent_hash: 0x0000000000000000000000000000000000000000000000000000000000000000, number: 0, state_root: 0x09290653ed33a76c68bcad4b0e10decad0f1f33a503ba5e1a8aae4ab056
Jan 05 17:52:18 devsgx03 encointer-worker[17149]:
Jan 05 17:52:18 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:18Z INFO  substratee_worker_enclave] Initializing Chain Relay!
Jan 05 17:52:18 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:18Z INFO  substratee_worker_enclave::io::light_validation] Found already initialized chain relay with Genesis Hash: 0x2b673afeff4a17e65fb3248fe9ac2a74998508a5c43
Jan 05 17:52:18 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:18Z INFO  substratee_worker_enclave::io::light_validation] Chain Relay state: LightValidationTest { num_relays: 1, tracked_relays: {1: RelayInfo { last_finalized
Jan 05 17:52:18 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:18Z INFO  encointer_worker::enclave::api] Latest Header Header { parent_hash: 0x0000000000000000000000000000000000000000000000000000000000000000, number: 0, stat
Jan 05 17:52:18 devsgx03 encointer-worker[17149]: [2021-01-05T16:52:18Z INFO  encointer_worker] Finished initializing chain relay, syncing....
Jan 05 17:52:18 devsgx03 encointer-worker[17149]: Chain Relay is synced until block: 0
Jan 05 17:52:18 devsgx03 encointer-worker[17149]: Last finalized block number: 805215

It seems the MultiAddress type is a breaking change for our chain relay. Probably should reset the chain entirely and not waste energy on this issue

@brenzi brenzi changed the title worker fails to sync properly after runtime V6 update worker fails to sync properly after runtime V6 update caused by MultiAddress type change Jan 5, 2021
@brenzi brenzi mentioned this issue Jan 5, 2021
Open
@brenzi brenzi changed the title worker fails to sync properly after runtime V6 update caused by MultiAddress type change worker fails to sync properly after runtime V6 update Jan 6, 2021
@brenzi
Copy link
Member Author

brenzi commented Jan 6, 2021 •
edited
Loading

MultiAddress type could be caused by:

currently, sgx_runtime still has old AccountId type, while the chain uses MultiAddress

NO, the error panics in the worker, not the enclave.....
it's the get_signed_block function that panics. Why only after fetching 400k blocks? (when updating runtime to V6, introducing MultiAddress)

@brenzi brenzi mentioned this issue Jan 6, 2021
Open
@brenzi brenzi added the wontfix This will not be worked on label Jan 7, 2021
@brenzi
Copy link
Member Author

brenzi commented Jan 7, 2021

Cantillon had to be reset. Not worth the effort to fix this before we fix integritee-network#85

@brenzi brenzi closed this as completed Jan 7, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working wontfix This will not be worked on
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@brenzi