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

shielding-unshielding example gets stuck at transferring incognito from Alice to Bob #175

Closed
brenzi opened this issue Sep 9, 2020 · 3 comments
Closed

shielding-unshielding example gets stuck at transferring incognito from Alice to Bob #175

brenzi opened this issue Sep 9, 2020 · 3 comments

Comments

@brenzi
Copy link
Collaborator

brenzi commented Sep 9, 2020

client log

./demo_shielding_unshielding.sh
Using node-port 9944
Using worker-port 2000

* Query on-chain enclave registry:
number of workers registered: 1
Enclave 1
   AccountId: 5EJKqXP8mX16oHPAKgrefhhKFYSH6DWT9SM8NYxJdWmQ6vFa
   MRENCLAVE: 2s5DNqVD4WDQzkqSUcHrTprBraTASLEqQVNFnMLHVyAd
   RA timestamp: 2020-09-09 08:08:37 UTC
   URL: 127.0.0.1:2000

* Reading MRENCLAVE of first worker
  MRENCLAVE = 2s5DNqVD4WDQzkqSUcHrTprBraTASLEqQVNFnMLHVyAd

* Get balance of Alice's on-chain account
balance for //Alice is 1152920504286846833

* Get balance of Bob's on-chain account
balance for //Bob is 1152921504606846976

* Create a new incognito account for Alice
  Alice's incognito account = 5GjbUg3UwP7i8h67z4RNkxfjNUVhXGAvtpJozqpKdv6FkaCZ

* Create a new incognito account for Bob
  Bob's incognito account = 5EFfAuqhxxy4CDn2XCBVMqQrsALx7oeysALkwKLBZVmhwZey

* Shield 50000000000 tokens to Alice's incognito account
[+] Transaction got finalized. Hash: Some(0x673d4929f5ac67a90e8cf3bf6a7cb58f24d2c35ccb5f44c6259c8ce3f20b1fa5)


* Waiting 10 seconds

Get balance of Alice's incognito accountarg_who = "5GjbUg3UwP7i8h67z4RNkxfjNUVhXGAvtpJozqpKdv6FkaCZ"
50000000000

* Get balance of Alice's on-chain account
balance for //Alice is 1152920454286846833

* Send 25000000000 funds from Alice's incognito account to Bob's incognito account
send trusted call transfer from 5GjbUg3UwP7i8h67z4RNkxfjNUVhXGAvtpJozqpKdv6FkaCZ to 5EFfAuqhxxy4CDn2XCBVMqQrsALx7oeysALkwKLBZVmhwZey: 25000000000
[2020-09-09T08:09:18Z ERROR substrate_api_client] couldn't decode event record list

### waiting forever.....

worker log

[2020-09-09T08:09:30Z INFO  substratee_worker_enclave] Found CallWorker extrinsic in block:                                                                                        
    Call: [6, 2]                                                                                                                                                                   
    Request:                                                                                                                                                                       
    shard: 2s5DNqVD4WDQzkqSUcHrTprBraTASLEqQVNFnMLHVyAd                                                                                                                            
    cyphertext: [79, 43, 91, 234, 226, 209, 200, 82, 97, 181, 167, 135, 35, 16, 112, 73, 237, 116, 115, 168, 106, 187, 89, 102, 100, 170, 122, 84, 153, 248, 115, 235, 214, 88, 117
, 147, 165, 81, 43, 115, 232, 159, 93, 164, 160, 209, 171, 110, 197, 161, 205, 132, 142, 221, 221, 41, 177, 42, 145, 22, 195, 173, 70, 22, 40, 163, 41, 118, 218, 41, 188, 23, 214,
 108, 121, 69, 3, 250, 245, 197, 88, 173, 194, 216, 238, 38, 188, 192, 190, 253, 46, 206, 156, 195, 112, 242, 166, 250, 72, 213, 99, 236, 62, 23, 215, 133, 21, 247, 47, 128, 75, 2
45, 44, 32, 38, 20, 163, 9, 49, 230, 204, 225, 11, 108, 85, 245, 12, 50, 40, 17, 50, 145, 89, 203, 200, 253, 102, 49, 67, 125, 18, 177, 173, 246, 211, 236, 64, 228, 29, 100, 90, 0
, 168, 228, 168, 94, 213, 77, 109, 93, 66, 89, 25, 114, 100, 62, 90, 108, 245, 223, 143, 47, 237, 252, 41, 164, 191, 58, 15, 177, 22, 21, 20, 108, 246, 192, 113, 115, 9, 124, 152,
 32, 70, 202, 39, 64, 35, 220, 119, 54, 40, 19, 59, 240, 225, 203, 103, 68, 59, 92, 0, 36, 209, 226, 64, 36, 193, 178, 221, 155, 215, 181, 238, 144, 116, 24, 214, 227, 252, 238, 3
9, 248, 31, 178, 201, 144, 10, 239, 121, 66, 222, 126, 107, 210, 33, 129, 19, 188, 98, 199, 54, 211, 176, 26, 171, 68, 32, 40, 164, 103, 245, 160, 119, 162, 218, 130, 122, 175, 32
, 173, 204, 205, 204, 179, 177, 253, 207, 14, 207, 252, 127, 32, 206, 141, 31, 217, 87, 15, 166, 162, 240, 85, 78, 120, 28, 116, 126, 240, 29, 234, 23, 161, 36, 34, 168, 196, 180,
 150, 221, 182, 232, 26, 21, 11, 140, 54, 134, 131, 12, 24, 173, 197, 209, 211, 45, 128, 245, 140, 100, 230, 133, 136, 50, 233, 114, 78, 226, 143, 33, 254, 180, 234, 238, 179, 195
, 122, 183, 94, 95, 146, 248, 111, 150, 140, 159, 55, 154, 111, 92, 179, 161, 28, 101, 61, 130, 176, 232, 67, 230, 38, 252, 10, 83, 84, 165, 93, 98, 75, 250, 115, 151, 165, 194, 7
3]                                                                                                                                                                                 
[2020-09-09T08:09:30Z DEBUG substratee_worker_enclave] decrypt the call                                                                                                            
[2020-09-09T08:09:30Z DEBUG substratee_worker_enclave] query mrenclave of self                                                                                                     
[2020-09-09T08:09:30Z DEBUG substratee_worker_enclave::attestation]     [Enclave] EPID group id = [200, 11, 0, 0]                                                                  
[2020-09-09T08:09:30Z DEBUG substratee_worker_enclave::attestation]     [Enclave] Report creation successful. mr_signer.m = [131, 215, 25, 231, 125, 234, 202, 20, 112, 246, 186, 2
46, 42, 77, 119, 67, 3, 200, 153, 219, 105, 2, 15, 156, 112, 238, 29, 252, 8, 199, 206, 158]                                                                                       
[2020-09-09T08:09:30Z DEBUG substratee_worker_enclave] MRENCLAVE of self is 2s5DNqVD4WDQzkqSUcHrTprBraTASLEqQVNFnMLHVyAd                                                           
[2020-09-09T08:09:30Z DEBUG substratee_worker_enclave] Update STF storage!                                                                                                         
[2020-09-09T08:09:30Z DEBUG substratee_worker_enclave] execute STF                                                                                                                 
[2020-09-09T08:09:30Z ERROR substratee_worker_enclave] Error performing Stf::execute. Error: Dispatch
@brenzi brenzi mentioned this issue Sep 9, 2020
Closed
@brenzi
Copy link
Collaborator Author

brenzi commented Sep 9, 2020 •
edited
Loading

caused by zero balance of alice incognito account. but why? querying balance on the worker-api shows the correct balance. but when calling balance_transfer alice has zero:


shield 

[2020-09-09T14:03:07Z INFO  substratee_worker_enclave] Found ShieldFunds extrinsic in block:
    Call: [6, 4]
    Account Encrypted [137, 6, 230, 120, 192, 168, 70, 51, 203, 39, 229, 74, 254, 21, 230, 23, 129, 181, 245, 141, 98, 8, 222, 230, 19, 171, 45, 129, 75, 34, 137, 111, 179, 56, 25
2, 130, 113, 4, 95, 174, 145, 117, 53, 213, 94, 39, 105, 149, 254, 19, 204, 151, 235, 156, 82, 11, 122, 230, 212, 114, 96, 161, 23, 125, 6, 210, 88, 125, 207, 97, 6, 54, 140, 185,
 176, 202, 3, 214, 104, 13, 177, 139, 74, 201, 137, 9, 75, 81, 239, 210, 125, 152, 21, 42, 16, 158, 189, 239, 216, 52, 95, 192, 146, 21, 62, 245, 163, 3, 216, 243, 77, 226, 26, 81
, 6, 50, 62, 71, 246, 174, 65, 47, 240, 7, 198, 161, 157, 180, 242, 170, 0, 146, 251, 213, 112, 117, 181, 242, 165, 223, 226, 64, 111, 238, 204, 111, 147, 11, 137, 66, 79, 187, 18
7, 25, 217, 236, 246, 200, 92, 119, 82, 104, 69, 132, 109, 180, 121, 33, 157, 61, 200, 224, 66, 234, 168, 9, 249, 52, 225, 132, 73, 191, 112, 29, 51, 57, 68, 255, 26, 68, 235, 12,
 111, 62, 201, 99, 20, 125, 103, 23, 188, 229, 252, 235, 29, 180, 163, 130, 25, 254, 116, 222, 154, 207, 16, 67, 44, 131, 101, 50, 187, 227, 45, 241, 65, 123, 31, 136, 80, 103, 73
, 191, 23, 58, 248, 70, 82, 188, 221, 135, 80, 153, 96, 206, 0, 181, 20, 225, 101, 211, 231, 5, 250, 193, 102, 56, 19, 76, 101, 60, 216, 244, 113, 40, 24, 252, 165, 159, 49, 184,
186, 158, 54, 213, 182, 74, 196, 29, 234, 49, 227, 250, 198, 57, 151, 51, 126, 83, 19, 9, 32, 1, 203, 9, 39, 87, 81, 143, 65, 158, 255, 160, 10, 233, 233, 154, 220, 68, 14, 173, 8
5, 237, 113, 173, 93, 57, 59, 151, 208, 186, 230, 174, 237, 137, 99, 144, 154, 167, 115, 185, 145, 164, 48, 150, 27, 57, 15, 167, 110, 251, 12, 91, 35, 167, 78, 105, 36, 127, 158,
 203, 111, 65, 227, 5, 89, 0, 188, 112, 4, 165, 5, 131, 236, 216, 106, 215, 18, 133, 104, 2, 123, 115, 227, 12, 63, 125, 41, 116, 125, 77, 241, 140, 94, 21]
    Amount: 50000000000
    Shard: 0x5ae94e231973d148a0b314eba2e0141e764c85339cf1ca4681953aed65b1c378
[2020-09-09T14:03:07Z DEBUG substratee_stf::sgx] initializing stf state
[2020-09-09T14:03:07Z DEBUG substratee_worker_enclave] decrypt the call
[2020-09-09T14:03:07Z DEBUG substratee_stf::sgx] balance_shield([ac, 2a, 81, 1, b9, 2a, d3, 5c, 8e, c7, b7, 94, 9f, ce, 65, ba, 23, cc, 53, 16, f1, b7, 96, e9, 69, 30, cc, b1, 93,
 cd, 3f, 2e], 50000000000)
[2020-09-09T14:03:07Z DEBUG substratee_worker_enclave::state] new state with hash=0xb9ac1b7846a64bd076cf8d992eafc7d2cca6f260c16273e11ca6b8a9212059fb written to ./shards/77t2gxmAQa
MvEAgJuYiBT5vs39aDc49eUMuxF8UMFXd9/state.bin
[2020-09-09T14:03:07Z DEBUG substratee_worker_enclave] Call hash 0x924bb3a294b554b77b03295cf0dd993652d512f343086b1dc473842a441ace4f


Synced 1442 blocks out of 1442 finalized blocks                                                                                                                                    
[2020-09-09T14:04:31Z INFO  substratee_worker::ws_server] [WS Server] Forwarding message to worker event loop: Binary([2, 1, 0, 172, 42, 129, 1, 185, 42, 211, 92, 142, 199, 183, 1
48, 159, 206, 101, 186, 35, 204, 83, 22, 241, 183, 150, 233, 105, 48, 204, 177, 147, 205, 63, 46, 26, 3, 22, 91, 175, 163, 64, 61, 217, 94, 231, 54, 134, 209, 120, 34, 195, 211, 1
95, 226, 9, 166, 105, 24, 50, 241, 45, 79, 96, 57, 31, 42, 8, 163, 152, 211, 135, 202, 1, 140, 89, 211, 59, 181, 96, 117, 17, 115, 2, 144, 21, 137, 229, 98, 204, 186, 203, 175, 10
4, 0, 229, 38, 64, 143, 90, 233, 78, 35, 25, 115, 209, 72, 160, 179, 20, 235, 162, 224, 20, 30, 118, 76, 133, 51, 156, 241, 202, 70, 129, 149, 58, 237, 101, 177, 195, 120])       
[2020-09-09T14:04:31Z INFO  substratee_worker::ws_server]      [WS Server] Got message 'WsServerRequest { client: Sender { token: Token(0), channel: mio::channel::SyncSender<Comma
nd>, connection_id: 1 }, request: StfState(trusted(TrustedGetterSigned { getter: free_balance(ac2a8101b92ad35c8ec7b7949fce65ba23cc5316f1b796e96930ccb193cd3f2e (5FxSih74...)), sign
ature: AnySignature(0x1a03165bafa3403dd95ee73686d17822c3d3c3e209a6691832f12d4f60391f2a08a398d387ca018c59d33bb56075117302901589e562ccbacbaf6800e526408f) }), 0x5ae94e231973d148a0b31
4eba2e0141e764c85339cf1ca4681953aed65b1c378) }'.                                                                                                                                   
[2020-09-09T14:04:31Z INFO  substratee_worker::ws_server]      [WS Server] Query state                                                                                             
[2020-09-09T14:04:31Z DEBUG substratee_worker_enclave] verifying signature of TrustedGetterSigned                                                                                  
[2020-09-09T14:04:31Z DEBUG substratee_worker_enclave::state] State loaded from ./shards/77t2gxmAQaMvEAgJuYiBT5vs39aDc49eUMuxF8UMFXd9/state.bin with size 518B, deserializing...   
[2020-09-09T14:04:31Z DEBUG substratee_worker_enclave] Update STF storage!                                                                                                         
[2020-09-09T14:04:31Z INFO  substratee_stf::sgx] No specific storage updates needed for getter. Returning those for on block: trusted(TrustedGetterSigned { getter: free_balance(),
 signature: <wasm:stripped> })                                                                                                                                                     
[2020-09-09T14:04:31Z DEBUG substratee_worker_enclave] calling into STF to get state                                                                                               
[2020-09-09T14:04:31Z DEBUG substratee_stf::sgx] AccountInfo for [ac, 2a, 81, 1, b9, 2a, d3, 5c, 8e, c7, b7, 94, 9f, ce, 65, ba, 23, cc, 53, 16, f1, b7, 96, e9, 69, 30, cc, b1, 93
, cd, 3f, 2e] is <wasm:stripped>                                                                                                                                                   
[2020-09-09T14:04:31Z DEBUG substratee_stf::sgx] Account free balance is 50000000000                                                                                               
[2020-09-09T14:04:31Z DEBUG substratee_worker_enclave] returning getter result            


2020-09-09T14:05:55Z INFO  substratee_worker_enclave] Found CallWorker extrinsic in block:
    Call: [6, 2]
    Request:
    shard: 77t2gxmAQaMvEAgJuYiBT5vs39aDc49eUMuxF8UMFXd9
    cyphertext: [28, 215, 71, 170, 81, 189, 65, 139, 232, 119, 136, 174, 171, 239, 63, 157, 12, 2, 18, 52, 100, 165, 40, 131, 206, 213, 244, 18, 184, 114, 142, 114, 214, 49, 60, 1
71, 58, 60, 39, 205, 4, 89, 223, 163, 168, 173, 208, 77, 81, 69, 154, 138, 101, 148, 69, 4, 188, 39, 79, 112, 53, 136, 115, 30, 78, 15, 26, 178, 59, 182, 32, 34, 75, 157, 170, 188
, 53, 195, 247, 20, 115, 219, 200, 36, 114, 246, 57, 180, 201, 20, 143, 59, 199, 108, 65, 180, 8, 252, 45, 122, 111, 35, 82, 143, 164, 196, 66, 105, 206, 4, 206, 117, 133, 217, 27
, 171, 34, 146, 131, 69, 215, 197, 45, 192, 246, 20, 168, 122, 5, 176, 223, 218, 224, 116, 181, 254, 42, 150, 133, 64, 204, 253, 76, 64, 228, 217, 211, 78, 35, 16, 224, 119, 60, 1
92, 2, 45, 126, 15, 67, 68, 97, 117, 110, 45, 242, 241, 102, 195, 121, 52, 97, 236, 204, 155, 177, 38, 147, 105, 132, 243, 213, 24, 230, 152, 1, 176, 96, 139, 128, 142, 245, 152,
235, 67, 86, 220, 218, 105, 108, 241, 130, 155, 241, 247, 42, 117, 145, 22, 232, 42, 248, 115, 11, 10, 85, 150, 198, 172, 208, 248, 40, 95, 226, 123, 47, 36, 167, 19, 48, 147, 202
, 194, 87, 129, 131, 227, 59, 241, 230, 156, 49, 16, 84, 81, 99, 117, 233, 9, 119, 201, 123, 94, 237, 57, 173, 68, 108, 236, 114, 87, 11, 9, 83, 90, 207, 2, 122, 146, 30, 104, 220
, 216, 98, 87, 152, 82, 47, 65, 127, 10, 144, 42, 211, 81, 222, 110, 24, 44, 176, 161, 91, 145, 168, 233, 121, 249, 18, 68, 106, 182, 188, 212, 25, 208, 80, 209, 93, 147, 201, 94,
 121, 167, 21, 244, 167, 56, 135, 202, 248, 209, 76, 210, 225, 95, 103, 51, 149, 230, 226, 20, 30, 19, 29, 183, 219, 254, 233, 177, 205, 31, 176, 43, 130, 88, 241, 111, 187, 8, 253, 2, 32, 124, 21, 49, 197, 233, 210, 232, 172, 134, 92, 186, 34, 123, 128, 46, 111, 238, 182, 139, 95, 156, 136, 95, 174, 227, 166, 88, 174, 183, 161, 7, 217, 184]
[2020-09-09T14:05:55Z DEBUG substratee_worker_enclave] decrypt the call
[2020-09-09T14:05:55Z DEBUG substratee_worker_enclave] query mrenclave of self
[2020-09-09T14:05:55Z DEBUG substratee_worker_enclave::attestation]     [Enclave] EPID group id = [200, 11, 0, 0]
[2020-09-09T14:05:55Z DEBUG substratee_worker_enclave::attestation]     [Enclave] Report creation successful. mr_signer.m = [131, 215, 25, 231, 125, 234, 202, 20, 112, 246, 186, 246, 42, 77, 119, 67, 3, 200, 153, 219, 105, 2, 15, 156, 112, 238, 29, 252, 8, 199, 206, 158]
[2020-09-09T14:05:55Z DEBUG substratee_worker_enclave] MRENCLAVE of self is 77t2gxmAQaMvEAgJuYiBT5vs39aDc49eUMuxF8UMFXd9
[2020-09-09T14:05:55Z DEBUG substratee_worker_enclave::state] State loaded from ./shards/77t2gxmAQaMvEAgJuYiBT5vs39aDc49eUMuxF8UMFXd9/state.bin with size 518B, deserializing...
[2020-09-09T14:05:55Z DEBUG substratee_worker_enclave] Update STF storage!
[2020-09-09T14:05:55Z DEBUG substratee_worker_enclave] execute STF
[2020-09-09T14:05:55Z DEBUG substratee_stf::sgx] balance_transfer([ac, 2a, 81, 1, b9, 2a, d3, 5c, 8e, c7, b7, 94, 9f, ce, 65, ba, 23, cc, 53, 16, f1, b7, 96, e9, 69, 30, cc, b1, 93, cd, 3f, 2e], [54, 36, 48, 2a, 21, 42, e9, ea, 90, fd, c4, 82, 5, 48, 9d, 52, 3e, 25, ac, 62, f9, 87, 72, c3, 6c, 11, 78, 7d, 37, b0, 13, 7], 25000000000)
[2020-09-09T14:05:55Z DEBUG substratee_stf::sgx] sender balance is zero
[2020-09-09T14:05:55Z ERROR substratee_worker_enclave] Error performing Stf::execute. Error: Dispatch("balance_transfer")




[2020-09-09T14:09:01Z INFO  substratee_worker_enclave] Found ShieldFunds extrinsic in block:
    Call: [6, 4]
    Account Encrypted [124, 85, 46, 80, 91, 31, 19, 0, 250, 61, 38, 150, 174, 10, 234, 116, 123, 147, 35, 127, 45, 158, 143, 228, 15, 185, 88, 221, 94, 55, 99, 233, 253, 242, 121, 161, 155, 229, 127, 220, 89, 23, 125, 149, 193, 47, 118, 219, 57, 196, 237, 51, 136, 98, 43, 156, 157, 166, 128, 229, 75, 77, 8, 85, 121, 239, 85, 81, 140, 45, 95, 156, 8, 95, 120, 30, 143, 208, 191, 90, 164, 45, 186, 23, 215, 226, 37, 116, 110, 11, 195, 228, 11, 12, 48, 7, 187, 112, 157, 23, 41, 70, 200, 92, 45, 208, 156, 189, 11, 226, 235, 144, 59, 81,
127, 21, 150, 222, 121, 139, 34, 249, 79, 243, 66, 78, 85, 43, 139, 221, 183, 70, 3, 79, 211, 211, 162, 208, 77, 146, 135, 179, 130, 192, 96, 78, 2, 192, 26, 151, 64, 253, 202, 173, 231, 69, 120, 195, 119, 168, 87, 152, 134, 183, 41, 19, 22, 231, 220, 68, 226, 240, 228, 241, 40, 44, 208, 220, 247, 169, 55, 133, 187, 159, 83, 170, 6, 186, 100, 81, 188, 84,
7, 26, 215, 152, 73, 116, 103, 245, 132, 116, 40, 148, 114, 238, 96, 223, 125, 191, 53, 14, 0, 51, 75, 19, 83, 199, 76, 185, 208, 96, 239, 60, 109, 127, 224, 215, 49, 84, 114, 110, 55, 228, 214, 190, 48, 113, 121, 134, 107, 66, 144, 255, 221, 243, 127, 211, 0, 121, 27, 9, 120, 32, 183, 38, 139, 129, 164, 135, 183, 234, 48, 253, 204, 42, 223, 101, 181, 252, 74, 152, 172, 151, 44, 77, 134, 218, 229, 117, 32, 252, 12, 92, 170, 97, 249, 42, 210, 166, 180, 52, 249, 239, 91, 167, 247, 174, 86, 231, 133, 129, 102, 129, 139, 100, 235, 141, 216, 98, 160, 111, 11, 199, 166, 251, 206, 31, 52, 25, 36, 166, 253, 220, 181, 96, 175, 241, 224, 77, 127, 221, 53, 46, 111, 195, 111, 143, 136, 179, 245, 233, 239, 185, 205, 243, 234, 196, 227, 24, 14, 118, 9, 200, 122, 228, 117, 7, 98, 47, 88, 108, 60, 1, 214, 79, 88, 29, 44, 70, 10, 138, 170, 231, 6, 153, 15, 32, 27, 236, 222, 204, 254, 40]
    Amount: 50000000000
    Shard: 0x5ae94e231973d148a0b314eba2e0141e764c85339cf1ca4681953aed65b1c378
[2020-09-09T14:09:01Z DEBUG substratee_worker_enclave::state] State loaded from ./shards/77t2gxmAQaMvEAgJuYiBT5vs39aDc49eUMuxF8UMFXd9/state.bin with size 518B, deserializing...
[2020-09-09T14:09:01Z DEBUG substratee_worker_enclave] decrypt the call
[2020-09-09T14:09:01Z DEBUG substratee_stf::sgx] balance_shield([ac, 2a, 81, 1, b9, 2a, d3, 5c, 8e, c7, b7, 94, 9f, ce, 65, ba, 23, cc, 53, 16, f1, b7, 96, e9, 69, 30, cc, b1, 93, cd, 3f, 2e], 50000000000)
[2020-09-09T14:09:01Z DEBUG substratee_worker_enclave::state] new state with hash=0x4cb598fbf4b1dd70bd5e228fcf323f4e683a33f8b8bc1842cd5e598945291666 written to ./shards/77t2gxmAQaMvEAgJuYiBT5vs39aDc49eUMuxF8UMFXd9/state.bin
[2020-09-09T14:09:01Z DEBUG substratee_worker_enclave] Call hash 0x051a52d53e41704074e2312490a66b6c7bc5895e5b6eaffd672cb5688f80e65d




Synced 1493 blocks out of 1493 finalized blocks                                                                                                                                    
[2020-09-09T14:09:42Z INFO  substratee_worker] Ignoring event EventRecord { phase: Phase::ApplyExtrinsic(0), event: Event::system(RawEvent::ExtrinsicSuccess(DispatchInfo { weight:
 159000000, class: DispatchClass::Mandatory, pays_fee: Pays::Yes })), topics: [] }                                                                                                 
[2020-09-09T14:09:42Z INFO  substratee_worker::ws_server] [WS Server] Forwarding message to worker event loop: Binary([2, 1, 0, 172, 42, 129, 1, 185, 42, 211, 92, 142, 199, 183, 1
48, 159, 206, 101, 186, 35, 204, 83, 22, 241, 183, 150, 233, 105, 48, 204, 177, 147, 205, 63, 46, 254, 108, 12, 59, 8, 4, 124, 80, 218, 134, 203, 78, 85, 80, 100, 18, 100, 19, 45,
 201, 125, 125, 247, 255, 59, 175, 169, 13, 131, 247, 182, 100, 40, 110, 222, 186, 94, 189, 5, 131, 108, 195, 114, 27, 10, 218, 93, 84, 65, 89, 204, 114, 149, 169, 228, 76, 117, 1
, 131, 47, 177, 61, 17, 128, 90, 233, 78, 35, 25, 115, 209, 72, 160, 179, 20, 235, 162, 224, 20, 30, 118, 76, 133, 51, 156, 241, 202, 70, 129, 149, 58, 237, 101, 177, 195, 120])  
[2020-09-09T14:09:42Z INFO  substratee_worker::ws_server]      [WS Server] Got message 'WsServerRequest { client: Sender { token: Token(0), channel: mio::channel::SyncSender<Comma
nd>, connection_id: 4 }, request: StfState(trusted(TrustedGetterSigned { getter: free_balance(ac2a8101b92ad35c8ec7b7949fce65ba23cc5316f1b796e96930ccb193cd3f2e (5FxSih74...)), sign
ature: AnySignature(0xfe6c0c3b08047c50da86cb4e5550641264132dc97d7df7ff3bafa90d83f7b664286edeba5ebd05836cc3721b0ada5d544159cc7295a9e44c7501832fb13d1180) }), 0x5ae94e231973d148a0b31
4eba2e0141e764c85339cf1ca4681953aed65b1c378) }'.                                                                                                                                   
[2020-09-09T14:09:42Z INFO  substratee_worker::ws_server]      [WS Server] Query state                                                                                             
[2020-09-09T14:09:42Z DEBUG substratee_worker_enclave] verifying signature of TrustedGetterSigned                                                                                  
[2020-09-09T14:09:42Z DEBUG substratee_worker_enclave::state] State loaded from ./shards/77t2gxmAQaMvEAgJuYiBT5vs39aDc49eUMuxF8UMFXd9/state.bin with size 518B, deserializing...   
[2020-09-09T14:09:42Z DEBUG substratee_worker_enclave] Update STF storage!                                                                                                         
[2020-09-09T14:09:42Z INFO  substratee_stf::sgx] No specific storage updates needed for getter. Returning those for on block: trusted(TrustedGetterSigned { getter: free_balance(),
 signature: <wasm:stripped> })                                                                                                                                                     
[2020-09-09T14:09:42Z DEBUG substratee_worker_enclave] calling into STF to get state                                                                                               
[2020-09-09T14:09:42Z DEBUG substratee_stf::sgx] AccountInfo for [ac, 2a, 81, 1, b9, 2a, d3, 5c, 8e, c7, b7, 94, 9f, ce, 65, ba, 23, cc, 53, 16, f1, b7, 96, e9, 69, 30, cc, b1, 93
, cd, 3f, 2e] is <wasm:stripped>                                                                                                                                                   
[2020-09-09T14:09:42Z DEBUG substratee_stf::sgx] Account free balance is 100000000000                                                                                              
[2020-09-09T14:09:42Z DEBUG substratee_worker_enclave] returning getter result     
    


           2020-09-09T14:15:42Z INFO  substratee_worker_enclave] Found CallWorker extrinsic in block:
    Call: [6, 2]
    Request:
    shard: 77t2gxmAQaMvEAgJuYiBT5vs39aDc49eUMuxF8UMFXd9
    cyphertext: [106, 145, 83, 231, 202, 85, 69, 41, 58, 96, 171, 202, 132, 105, 39, 66, 13, 67, 43, 243, 35, 145, 170, 19, 6, 227, 132, 196, 119, 13, 58, 139, 247, 74, 102, 249,
108, 192, 150, 188, 163, 194, 71, 160, 211, 83, 107, 119, 92, 223, 164, 8, 126, 238, 5, 55, 139, 154, 53, 163, 146, 98, 115, 122, 77, 32, 82, 26, 125, 11, 75, 211, 130, 28, 42, 104, 210, 0, 238, 56, 125, 41, 61, 251, 70, 241, 113, 149, 10, 123, 82, 204, 209, 229, 146, 224, 52, 155, 130, 170, 253, 158, 147, 244, 37, 132, 66, 6, 97, 15, 148, 111, 246, 207, 47, 134, 81, 139, 146, 130, 128, 60, 242, 140, 13, 98, 129, 53, 155, 143, 139, 55, 159, 49, 48, 29, 89, 132, 115, 228, 253, 11, 12, 16, 230, 79, 45, 216, 249, 223, 16, 218, 195, 34, 231, 113, 194, 33, 241, 212, 2, 237, 134, 242, 153, 41, 57, 31, 52, 60, 227, 130, 218, 216, 178, 129, 30, 6, 4, 114, 88, 58, 228, 224, 237, 227, 60, 51, 38, 115, 250, 180, 161,
148, 24, 46, 165, 218, 255, 246, 159, 82, 232, 241, 202, 117, 125, 189, 131, 23, 146, 104, 186, 85, 77, 61, 226, 78, 216, 220, 191, 9, 28, 202, 122, 17, 63, 17, 36, 62, 215, 31, 64, 74, 0, 35, 249, 122, 203, 230, 237, 154, 107, 23, 51, 73, 86, 36, 92, 25, 241, 86, 48, 188, 224, 195, 248, 174, 50, 166, 103, 252, 199, 209, 183, 111, 237, 49, 205, 34, 145, 80, 98, 203, 220, 20, 91, 26, 179, 95, 29, 51, 244, 243, 211, 145, 254, 128, 91, 88, 213, 187, 112, 204, 220, 232, 202, 130, 34, 253, 34, 167, 222, 136, 60, 181, 173, 176, 220, 214, 177, 111, 159, 125, 55, 95, 106, 180, 228, 188, 214, 77, 109, 118, 39, 183, 125, 41, 167, 34, 188, 51, 200, 123, 68, 173, 160, 63, 127, 102, 139, 0, 154, 191, 14, 142, 135, 114,
139, 217, 141, 246, 224, 114, 121, 208, 209, 28, 12, 179, 105, 3, 245, 205, 207, 41, 143, 201, 42, 250, 45, 250, 123, 221, 145, 233, 72, 55, 135, 236, 64, 52, 117, 178]
[2020-09-09T14:15:42Z DEBUG substratee_worker_enclave] decrypt the call
[2020-09-09T14:15:42Z DEBUG substratee_worker_enclave] query mrenclave of self
[2020-09-09T14:15:42Z DEBUG substratee_worker_enclave::attestation]     [Enclave] EPID group id = [200, 11, 0, 0]
[2020-09-09T14:15:42Z DEBUG substratee_worker_enclave::attestation]     [Enclave] Report creation successful. mr_signer.m = [131, 215, 25, 231, 125, 234, 202, 20, 112, 246, 186, 246, 42, 77, 119, 67, 3, 200, 153, 219, 105, 2, 15, 156, 112, 238, 29, 252, 8, 199, 206, 158]
[2020-09-09T14:15:42Z DEBUG substratee_worker_enclave] MRENCLAVE of self is 77t2gxmAQaMvEAgJuYiBT5vs39aDc49eUMuxF8UMFXd9
[2020-09-09T14:15:42Z DEBUG substratee_worker_enclave::state] State loaded from ./shards/77t2gxmAQaMvEAgJuYiBT5vs39aDc49eUMuxF8UMFXd9/state.bin with size 518B, deserializing...
[2020-09-09T14:15:42Z DEBUG substratee_worker_enclave] Update STF storage!
[2020-09-09T14:15:42Z DEBUG substratee_worker_enclave] execute STF
[2020-09-09T14:15:42Z DEBUG substratee_stf::sgx] balance_transfer([ac, 2a, 81, 1, b9, 2a, d3, 5c, 8e, c7, b7, 94, 9f, ce, 65, ba, 23, cc, 53, 16, f1, b7, 96, e9, 69, 30, cc, b1, 93, cd, 3f, 2e], [54, 36, 48, 2a, 21, 42, e9, ea, 90, fd, c4, 82, 5, 48, 9d, 52, 3e, 25, ac, 62, f9, 87, 72, c3, 6c, 11, 78, 7d, 37, b0, 13, 7], 25000000000)
[2020-09-09T14:15:42Z DEBUG substratee_stf::sgx] sender balance is zero
[2020-09-09T14:15:42Z ERROR substratee_worker_enclave] Error performing Stf::execute. Error: Dispatch("balance_transfer")

@brenzi
Copy link
Collaborator Author

brenzi commented Sep 9, 2020 •
edited
Loading

more verbose logging shows that the correct state is loaded from disk

verified facts:

  • correct shard
  • correct state hash
  • correct AccountId

Why is the balance zero?

[2020-09-09T14:34:43Z INFO  substratee_worker_enclave] Found ShieldFunds extrinsic in block:                                                                                       
    Call: [6, 4]                                                                                                                                                                   
    Account Encrypted [71, 165, 88, 182, 194, 102, 11, 187, 36, 100, 192, 133, 201, 45, 68, 239, 193, 106, 73, 73, 218, 72, 240, 255, 59, 235, 31, 131, 166, 183, 201, 163, 134, 78
, 200, 140, 243, 44, 146, 212, 82, 225, 37, 98, 209, 173, 160, 113, 144, 236, 80, 180, 211, 103, 194, 79, 202, 113, 248, 138, 101, 114, 65, 176, 207, 137, 37, 91, 166, 109, 246, 1
59, 190, 193, 95, 135, 158, 148, 36, 98, 30, 54, 18, 209, 170, 89, 33, 224, 7, 231, 37, 54, 33, 175, 158, 70, 36, 214, 21, 54, 46, 211, 169, 229, 58, 94, 69, 61, 121, 255, 105, 47
, 89, 78, 71, 250, 145, 54, 181, 132, 122, 155, 7, 162, 255, 9, 156, 117, 253, 236, 122, 72, 192, 36, 23, 111, 85, 185, 55, 185, 12, 110, 244, 9, 91, 224, 1, 253, 125, 81, 73, 149
, 202, 214, 167, 132, 77, 53, 207, 124, 7, 229, 113, 222, 53, 213, 232, 182, 251, 26, 57, 140, 212, 208, 110, 56, 74, 162, 254, 6, 149, 27, 12, 135, 109, 171, 183, 119, 160, 81, 1
16, 126, 231, 254, 214, 129, 4, 135, 6, 191, 255, 44, 169, 237, 193, 112, 153, 84, 94, 106, 75, 93, 1, 70, 198, 176, 73, 75, 142, 49, 140, 112, 196, 74, 188, 168, 208, 201, 161, 2
55, 108, 76, 121, 1, 214, 1, 182, 180, 110, 88, 45, 188, 53, 70, 171, 180, 156, 192, 118, 147, 140, 44, 15, 37, 64, 194, 230, 12, 196, 150, 78, 238, 189, 206, 11, 253, 129, 150, 7
, 122, 225, 62, 117, 9, 41, 181, 163, 7, 229, 174, 30, 235, 34, 233, 97, 67, 130, 146, 55, 175, 123, 230, 50, 105, 72, 96, 3, 206, 6, 165, 215, 149, 63, 157, 159, 133, 156, 210, 1
39, 23, 65, 210, 158, 36, 28, 189, 249, 100, 48, 3, 86, 139, 49, 38, 158, 51, 242, 96, 22, 25, 234, 121, 8, 242, 229, 126, 21, 17, 2, 192, 152, 118, 254, 21, 60, 30, 153, 52, 250,
 69, 168, 113, 10, 21, 227, 89, 237, 245, 7, 132, 255, 249, 24, 60, 33, 160, 249, 204, 145, 112, 158, 167, 111, 138, 181, 39, 148, 47, 213, 1, 185, 142, 247, 193]                 
    Amount: 50000000000                                                                                                                                                            
    Shard: DqKhzFck35NamYm99UnHwf1UVWnhMaHhJbishhmAtsAH                                                                                                                            
[2020-09-09T14:34:43Z DEBUG substratee_stf::sgx] initializing stf state                                                                                                            
[2020-09-09T14:34:43Z DEBUG substratee_worker_enclave] decrypt the call                                                                                                            
[2020-09-09T14:34:43Z DEBUG substratee_stf::sgx] balance_shield([9a, 6b, b, 90, a6, 52, 8c, a1, 62, 20, ec, eb, f5, 84, eb, c2, 97, f7, be, 51, a0, fe, d5, b6, 8c, 20, 58, ab, b5,
 ca, 88, 33], 50000000000)                                                                                                                                                         
[2020-09-09T14:34:43Z DEBUG substratee_worker_enclave::state] new state with hash=0x198277237de2cec0e38a3c4a7958b34809a07c37d2b565bf5084d3d90dadf019 written to ./shards/DqKhzFck35
NamYm99UnHwf1UVWnhMaHhJbishhmAtsAH/state.bin                                                     



[2020-09-09T14:35:58Z INFO  substratee_worker::ws_server] [WS Server] Forwarding message to worker event loop: Binary([2, 1, 0, 154, 107, 11, 144, 166, 82, 140, 161, 98, 32, 236, 
235, 245, 132, 235, 194, 151, 247, 190, 81, 160, 254, 213, 182, 140, 32, 88, 171, 181, 202, 136, 51, 200, 8, 179, 193, 213, 160, 137, 216, 236, 142, 205, 171, 35, 29, 31, 178, 110
, 156, 16, 212, 32, 58, 245, 140, 15, 56, 211, 226, 142, 191, 209, 90, 226, 98, 151, 187, 29, 247, 244, 0, 139, 95, 82, 17, 201, 167, 232, 106, 149, 125, 35, 46, 15, 14, 43, 181, 
254, 62, 198, 211, 172, 13, 194, 132, 190, 173, 70, 14, 78, 31, 183, 155, 144, 159, 176, 72, 245, 4, 241, 250, 204, 66, 217, 224, 43, 214, 15, 18, 124, 55, 184, 17, 139, 149, 128,
 42])                                                                                                                                                                              
[2020-09-09T14:35:58Z INFO  substratee_worker::ws_server]      [WS Server] Got message 'WsServerRequest { client: Sender { token: Token(0), channel: mio::channel::SyncSender<Comma
nd>, connection_id: 1 }, request: StfState(trusted(TrustedGetterSigned { getter: free_balance(9a6b0b90a6528ca16220ecebf584ebc297f7be51a0fed5b68c2058abb5ca8833 (5FZB2ijb...)), sign
ature: AnySignature(0xc808b3c1d5a089d8ec8ecdab231d1fb26e9c10d4203af58c0f38d3e28ebfd15ae26297bb1df7f4008b5f5211c9a7e86a957d232e0f0e2bb5fe3ec6d3ac0dc284) }), 0xbead460e4e1fb79b909fb
048f504f1facc42d9e02bd60f127c37b8118b95802a) }'.                                                                                                                                   
[2020-09-09T14:35:58Z INFO  substratee_worker::ws_server]      [WS Server] Query state                                                                                             
[2020-09-09T14:35:58Z DEBUG substratee_worker_enclave] verifying signature of TrustedGetterSigned                                                                                  
[2020-09-09T14:35:58Z DEBUG substratee_worker_enclave::state] read state with hash 0x198277237de2cec0e38a3c4a7958b34809a07c37d2b565bf5084d3d90dadf019 read from ./shards/DqKhzFck35
NamYm99UnHwf1UVWnhMaHhJbishhmAtsAH/state.bin                                                                                                                                       
[2020-09-09T14:35:58Z DEBUG substratee_worker_enclave::state] State loaded from ./shards/DqKhzFck35NamYm99UnHwf1UVWnhMaHhJbishhmAtsAH/state.bin with size 518B, deserializing...   
[2020-09-09T14:35:58Z DEBUG substratee_worker_enclave] Update STF storage!                                                                                                         
[2020-09-09T14:35:58Z INFO  substratee_stf::sgx] No specific storage updates needed for getter. Returning those for on block: trusted(TrustedGetterSigned { getter: free_balance(),
 signature: <wasm:stripped> })                                                                                                                                                     
[2020-09-09T14:35:58Z DEBUG substratee_worker_enclave] calling into STF to get state                                                                                               
[2020-09-09T14:35:58Z DEBUG substratee_stf::sgx] AccountInfo for [9a, 6b, b, 90, a6, 52, 8c, a1, 62, 20, ec, eb, f5, 84, eb, c2, 97, f7, be, 51, a0, fe, d5, b6, 8c, 20, 58, ab, b5
, ca, 88, 33] is <wasm:stripped>                                                                                                                                                   
[2020-09-09T14:35:58Z DEBUG substratee_stf::sgx] Account free balance is 50000000000                                                                                               
[2020-09-09T14:35:58Z DEBUG substratee_worker_enclave] returning getter result                




[2020-09-09T14:36:43Z INFO  substratee_worker_enclave] Found CallWorker extrinsic in block:                                                                                        
    Call: [6, 2]                                                                                                                                                                   
    Request:                                                                                                                                                                       
    shard: DqKhzFck35NamYm99UnHwf1UVWnhMaHhJbishhmAtsAH                                                                                                                            
    cyphertext: [138, 133, 63, 20, 121, 154, 87, 96, 96, 75, 180, 33, 217, 72, 182, 51, 210, 247, 39, 127, 30, 222, 134, 209, 112, 70, 199, 86, 246, 161, 7, 46, 26, 53, 161, 134, 
247, 210, 32, 44, 5, 106, 244, 182, 240, 67, 9, 11, 93, 190, 59, 63, 65, 20, 181, 8, 152, 228, 105, 141, 183, 92, 206, 230, 42, 134, 250, 231, 157, 64, 152, 252, 143, 204, 181, 22
2, 49, 41, 47, 175, 143, 230, 205, 69, 83, 129, 200, 58, 47, 102, 206, 45, 107, 97, 183, 127, 235, 175, 97, 6, 125, 150, 123, 218, 17, 138, 195, 41, 233, 126, 67, 176, 54, 238, 12
5, 137, 119, 214, 153, 67, 175, 63, 133, 211, 47, 15, 17, 186, 236, 198, 25, 156, 20, 253, 38, 44, 181, 46, 30, 140, 98, 244, 108, 135, 243, 238, 171, 243, 146, 8, 67, 138, 245, 190, 240, 205, 157, 58, 105, 168, 0, 221, 87, 31, 79, 6, 91, 100, 179, 99, 173, 218, 180, 246, 233, 177, 179, 238, 61, 110, 29, 49, 229, 242, 169, 198, 215, 194, 69, 35, 25, 136, 166, 76, 141, 53, 111, 251, 93, 58, 82, 147, 136, 84, 75, 213, 100, 215, 92, 91, 127, 247, 212, 71, 22, 206, 45, 171, 70, 19, 39, 56, 62, 124, 38, 105, 128, 194, 218, 97, 170, 189, 29, 181, 8, 206, 11, 19, 43, 37, 203, 205, 3, 226, 222, 163, 140, 87, 109, 75, 169, 126, 54, 223, 110, 63, 86, 96, 154, 73, 232, 87, 48, 236, 122, 94, 43, 141, 209, 39, 25, 255,
40, 103, 207, 63, 152, 154, 216, 237, 243, 67, 156, 241, 108, 78, 118, 131, 79, 5, 184, 52, 35, 211, 191, 99, 183, 112, 247, 14, 103, 95, 234, 72, 65, 241, 122, 61, 45, 138, 68, 175, 23, 249, 104, 205, 191, 247, 28, 4, 168, 217, 3, 94, 186, 90, 113, 125, 47, 89, 155, 189, 121, 173, 208, 54, 37, 164, 185, 134, 40, 110, 188, 104, 46, 242, 234, 118, 173, 174, 48, 208, 93, 116, 231, 74, 188, 18, 220, 231, 227, 82, 149, 40, 15, 250, 53, 153, 207, 100, 33, 147, 96, 40, 20, 119, 215, 235, 90, 136, 205, 152, 62, 63]
[2020-09-09T14:36:43Z DEBUG substratee_worker_enclave] decrypt the call
[2020-09-09T14:36:43Z DEBUG substratee_worker_enclave] query mrenclave of self
[2020-09-09T14:36:43Z DEBUG substratee_worker_enclave::attestation]     [Enclave] EPID group id = [200, 11, 0, 0]
[2020-09-09T14:36:43Z DEBUG substratee_worker_enclave::attestation]     [Enclave] Report creation successful. mr_signer.m = [131, 215, 25, 231, 125, 234, 202, 20, 112, 246, 186, 246, 42, 77, 119, 67, 3, 200, 153, 219, 105, 2, 15, 156, 112, 238, 29, 252, 8, 199, 206, 158]
[2020-09-09T14:36:43Z DEBUG substratee_worker_enclave] MRENCLAVE of self is DqKhzFck35NamYm99UnHwf1UVWnhMaHhJbishhmAtsAH
[2020-09-09T14:36:43Z DEBUG substratee_worker_enclave::state] read state with hash 0x198277237de2cec0e38a3c4a7958b34809a07c37d2b565bf5084d3d90dadf019 read from ./shards/DqKhzFck35NamYm99UnHwf1UVWnhMaHhJbishhmAtsAH/state.bin
[2020-09-09T14:36:43Z DEBUG substratee_worker_enclave::state] State loaded from ./shards/DqKhzFck35NamYm99UnHwf1UVWnhMaHhJbishhmAtsAH/state.bin with size 518B, deserializing...
[2020-09-09T14:36:43Z DEBUG substratee_worker_enclave] Update STF storage!
[2020-09-09T14:36:43Z DEBUG substratee_worker_enclave] execute STF
[2020-09-09T14:36:43Z DEBUG substratee_stf::sgx] balance_transfer([9a, 6b, b, 90, a6, 52, 8c, a1, 62, 20, ec, eb, f5, 84, eb, c2, 97, f7, be, 51, a0, fe, d5, b6, 8c, 20, 58, ab, b5, ca, 88, 33], [28, 0, 74, 28, 1b, 2e, 16, c4, dc, 89, 5d, 3b, c5, f0, 55, ce, b8, d1, e7, 19, aa, 70, ff, e6, 68, 40, a6, da, e6, ab, 5d, 37], 25000000000)
[2020-09-09T14:36:43Z DEBUG substratee_stf::sgx] sender balance is zero
[2020-09-09T14:36:43Z ERROR substratee_worker_enclave] Error performing Stf::execute. Error: Dispatch("balance_transfer")

@brenzi
Copy link
Collaborator Author

brenzi commented Sep 9, 2020

Ok, got it:

https://github.com/scs/substraTEE-worker/blob/ee2eb1329447790e10aa56e7c6fe159fea67a449/stf/src/sgx.rs#L197-L203

we updated the nonce key hash for incognito accounts (which don't exist on chain) that key actually points to the entire AccountInfo which is then overwritten in STF state.

deleting these entries fixes this issue

@brenzi brenzi closed this as completed Sep 13, 2020
@Niederb Niederb mentioned this issue Jun 7, 2022
Closed
1 task
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@brenzi