ServiceID generation incorrect, Incorrect Wrangling of Work Results, Demonstrate Option<Hash> in assurances/orderedaccumulation data

[davxy]

We're not able to successfully execute the vector data/assurances/state_transitions/1_004.bin.

In particular the failure is due to an unexpected PVM execution result for code of service 0.

Looks like you expect this service code to write something somewhere, but as far as I can see the service accumulate exits almost immediately.

Have you built this pvm blob using the last pvm crates releases?
I ask because I see that :

1. for the Duna services you've not used the Service trait defined by jam-pvm-common crate (e.g. now accumulate is defined to return an Option<Hash>.
2. for the Parity services you're using an outdated Service trait definition. E.g. now accumulate returns an Option<Hash>

Using https://pvm.fluffylabs.dev I'm able to load bootstrap.pvm from this folder here: https://github.com/jam-duna/jamtestnet/tree/main/services/jam-duna/bootstrap. (but I'm not able to load bootsrap_blob.pvm. What is the difference between these two?)
The fluffylabs debugger shows that indeed the program exits immediately.

I don't know what's the issue exactly, so may be worth investigate together.

[jaymansfield]

Also unable to match starting with assurances/1_004.

My PVM executes it using the code hash and tracing it shows:

PC:5 - Jump ( jump to PC 22)
PC:22 - Load_imm_64 (load into reg 10)
PC:32 - Load_imm (load into reg 11)
PC:34 - Load_imm (load into reg 7)
PC:37 - Jump_Ind (jumps to HALT address)

There is no output hash since reg7=0.

What is the expected output @sourabhniyogi ?

[sourabhniyogi]

We are amidst modernizing the bootstrap/fib/trib/service built with polkatool (and then fib+trib+megatron) to ensure it conforms to wrangled tuples and Option<Hash>.

[sourabhniyogi]

My PVM executes it using the code hash and tracing it shows:

PC:5 - Jump ( jump to PC 22) PC:22 ...

Argh, we did not update our jump points 0/5/10/15 to 0/5/10 in 0.5.x. Thank you for the hint, we will do our fluffy difference check more thoroughly...

[davxy]

We will review and republish to match GP 0.6.x B.12 in a few days updating our current { fib, trib, megatron } services and then hopefully a similar JAM Rust SDK service set thereafter.

Alright, thank you @sourabhniyogi. To move the needle forward would be nice to first be able to execute the bootstrap accumulate code in https://github.com/jam-duna/jamtestnet/blob/main/data/assurances/state_transitions/1_004.json with matching results. Please ping me when this is ready for another shot. Ty

[sourabhniyogi]

@jaymansfield We have updated with new assurances dataset which at least has the 0/5/10 entrypoints corrected but we are still checking how to deal with Option<Hash> properly so it might be worth waiting or you could take a quick look.

I believe we'll have a first attempt to solve the Option<Hash> alongside authorization pool/queues with authorizers in genesis state in a couple of days ... we're reviewing 0.5.x + 0.6.x changes carefully (based on fluffy's GP annotations), to see what else we may have missed...

[davxy]

@sourabhniyogi

Small progress after your update, looks like now we're able to run the bootstrap code blob contained in 0004 trace.
But the results are still unexpected. I guess this is mostly dueto invalid hardcoded addresses in your sources?
Apparently when - in the host - we read data from the given pointers we get gibberish.

This is a detailed execution trace for your reference, after each instruction there is some detail about the effect of the executed instruction.

[2]: 5: charge_gas
  charge_gas: 1 (101 -> 100)

[3]: 5: jump 27

[4]: 27: charge_gas
  charge_gas: 29 (100 -> 71)

[5]: 27: sp = sp - 24
  sp = 0xfefdffe8

[6]: 30: u64 [sp + 16] = ra
  [0xfefdfff8] = ra = 0xffff0000

[7]: 33: u64 [sp + 8] = s0
  [0xfefdfff0] = s0 = 0x0

[8]: 36: u64 [sp] = s1
  [0xfefdffe8] = s1 = 0x0

[9]: 38: a0 = 0xfeff0000
  a0 = 0xfeff0000

[10]: 48: a1 = u64 [a0 + 32]
  a1 = u64 [0xfeff0020] = 0xe48d43ffec49d017 

[11]: 51: a2 = 0x64
  a2 = 0x64

[12]: 54: a3 = 0x64
  a3 = 0x64

[13]: 57: ecalli 9
  HOSTCALL NEW (index = 9)
    code_hash_ptr=0xfeff0000
      ⤷ code_hash=0x100000000000000001f0c14edc5fa3695abbfa1628c372b8b8bddfa71d8e083e
    code_len=16468894178823753751
    min_item_gas=100
    min_memo_gas=100
        
[14]: 59: s0 = a0
  s0 = 0xfffffffffffffff9

[15]: 61: s1 = 0xfefde000
  s1 = 0xfefde000

[16]: 71: u64 [s1 + 0] = 0
  u64 [0xfefde000] = 0x0

[17]: 73: u64 [s1 + 4] = a0
  u64 [0xfefde004] = a0 = 0xfffffffffffffff9

[18]: 76: a2 = 0xfefde004
  a2 = 0xfefde004

[19]: 86: a1 = 0x4
  a1 = 0x4

[20]: 89: a3 = 0x4
  a3 = 0x4

[21]: 92: a0 = 0xfefde000
  a0 = 0xfefde000

[22]: 102: ecalli 3
  HOSTCALL WRITE (index = 3)
    key_ptr=0xfefde000
    key_len=4
     ⤷ key=0x00000000
    value_ptr=-0xfefde004
    value_len=4
     ⤷ value=0xf9ffffff

[23]: 104: a1 = 0x98967f
  a1 = 0x98967f

[24]: 110: a2 = 0x64
  a2 = 0x64

[25]: 113: a0 = s0
  a0 = 0xfffffffffffffff9

[26]: 115: a3 = s1
  a3 = 0xfefde000

[27]: 117: ecalli 11
  HOSTCALL TRANSFER (index = 11)
    destination=18446744073709551609
    amount=9999999
    gas_limit=100
    memo_ptr=0xfefde000
      ⤷ memo=0x00000000f9ffffffffffffff00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000

[28]: 119: a0 = 0x0
  a0 = 0x0

[29]: 121: ra = u64 [sp + 16]
  ra = u64 [0xfefdfff8] = 0xffff0000

[30]: 124: s0 = u64 [sp + 8]
  s0 = u64 [0xfefdfff0] = 0x0

[31]: 127: s1 = u64 [sp]
  s1 = u64 [0xfefdffe8] = 0x0

[32]: 129: sp = sp + 0x18
  sp = 0xfefe0000

[33]: 132: ret

[sourabhniyogi]

We believe we have corrected our services in 0.6.2.3 release but are still working on:

1. wrangled operand tuples codec details and
2. useful Option<Hash> outputs

[davxy]

@sourabhniyogi I tested again with your updated blob, but I'm still encountering unexpected behavior in all three hostcalls. Let's tackle the issues one at a time, beginning with the first one: new service creation.

Rather than sharing the entire trace, I'll only provide the hostcall arguments I'm seeing in our hostcall handler:

HOSTCALL NEW
code_hash_ptr=0xfeff0000
  ⤷ code_hash=0x1000000000000000015e6bd3b7429fc6a109b46fa3153b92638f780bf0456dcd
code_len=235
min_item_gas=100
min_memo_gas=100

The first thing I notice is that this appears to be an invalid code hash.
In my handler, however, a new service is still created using these arguments.
Here's my analysis of your post state for this new service compared to what I expect.

[
    "0xffa60048009200e8000000000000000000000000000000000000000000000000",
    "0x1f2acc37e37dc4f99c3fc50202c92d0c148c6e73ef789a37189221e2b24c46fd3398980000000000640000000000000064000000000000003c0100000000000002000000",
    "service_account",
    "s=3901900966|c=0x1f2acc37e37dc4f99c3fc50202c92d0c148c6e73ef789a37189221e2b24c46fd b=10000435 g=100 m=100 l=316 i=2|clen=32"
]

1. As anticipated, the code hash here is noticeably different from the one passed to the hostcall. This makes me suspect that the code hash pointer in your new hostcall might still be incorrect.

2. There's a discrepancy in the new service ID. What algorithm did you use to generate this ID? For reference, my new service assigned ID is id = 272334947 = 0x103b8063.

3. Immediately after the NEW service creation, my service balance is set to 436. In your case, however, the balance at the end of the block is 10000435 (possibly due to the balance transfer at the end of your block exec?).

4. We seem to have matching values for g, m, l, and i. 🙂

Let's start by tackling issues 1, 2, and 3 for this NEW service creation.
Since there are a few inconsistencies, it might be helpful to proceed in small steps. Perhaps you could temporarily modify your code to focus solely on constructing a new service and see if we can align on this initial task. Once that's resolved, we can reintroduce the write call, followed by the transfer.

Taking this step-by-step approach should make the debugging process more manageable—otherwise, this could turn into a lengthy process! 😄

[jaymansfield]

Can confirm that I am also arriving at a new service ID of 272334947 and code hash of 0x10000000000000000100241f2acc37e37dc4f99c3fc50202c92d0c148c6e73ef. My balance is different though.

[sourabhniyogi]

@sourabhniyogi I tested again with your updated blob, but I'm still encountering unexpected behavior in all three hostcalls. Let's tackle the issues one at a time, beginning with the first one: new service creation.

Alright, thank you for taking the time to work with us on this. Its very clear to us that when you help one team you help like a dozen others, and we see that this step-by-step public derivation will help like two dozen others going through the process.

ServiceID computation

Our x_i computation of 0.6.2 (B.9)

s = 0
eta_0' = 592170100ab4055c92a269faf579e29e7e453d13549c0dc4f0120fc670ff357d
timeslot = 16
encode(s, eta_0', timeslot)_ = 0000000020592170100ab4055c92a269faf579e29e7e453d13549c0dc4f0120fc670ff357d10000000
hash(encoded) = a64792e833b594bab9bd59fabb3415502ea07256a3744896bf44847ee899efc4
hashed[:4] = a64792e8
decode(hashed[:4]) = 3901900710
decoded mod 4294966784 + 256= 3901900966 (little endian 0xa64892e8)

Which part did we get wrong? Another team seems to have the same answer above here, we must have a conceptual bug above..

hostNew

For the inputs and memory read of the host new call:

hostNew() [jam-duna #74 check]
code_hash_ptr=feff0000
  ==> code_hash_ptr=1f2acc37e37dc4f99c3fc50202c92d0c148c6e73ef789a37189221e2b24c46fd
code_len (w8)=235
min_item_gas (w9)=100
min_memo_gas (w10)=100

we appear to be off by 11 bytes somewhere

0x10000000000000000100241f2acc37e37dc4f99c3fc50202c92d0c148c6e73ef

vs

0x1f2acc37e37dc4f99c3fc50202c92d0c148c6e73ef789a37189221e2b24c46fd

We realized we are still getting our wrangling in order and hope we can explain this 11 byte shift soon -- thank you.

Also:

a_t (BS+BI*ai +BL*al)=100+10*2+1*316=436
... Service Balance 10000000000 >= threshold = 436 [9.3 a_t](https://graypaper.fluffylabs.dev/#/293bf5a/111801111b01) 

New Service xi (w7)=3901900966 to be stored 
ServiceAccount 3901900966 
CodeHash: 0x1f2acc37e37dc4f99c3fc50202c92d0c148c6e73ef789a37189221e2b24c46fd
 B=436, G=100 M=100 L=316, I=2 

Totally makes sense to work step by step -- but rather than republish a new bootstrap service without a write + transfer (which I totally agree makes reasoning harder), we'll just disable the effects of our "hostWrite()" and "hostTransfer()" host function implementation until we have consensus on "hostNew()" for getting the serviceid correct and the code_hash_ptr memory alignment correct. Then we can turn on the write, get consensus, then the transfer. Does that make sense?

Again -- thank you for engaging with us! Having so many teams coming into spec alignment is a new kind of joy, relative to making things work as just one team.

[jaymansfield]

@sourabhniyogi

For the service ID generation here is my encode(s, eta_0', timeslot) value:
0x00000000592170100ab4055c92a269faf579e29e7e453d13549c0dc4f0120fc670ff357d10000000

The beginning differs from yours. You seem to have a "20" between service ID and eta_0'.

[sourabhniyogi]

Excellent -- since eta_0' is a Hash (see 6.21) and "this is omitted in case of fixed-length terms such as hashes" applies:

Then by C.3 we should drop the 0x20. Then we arrive at the same answer:

s = 0
eta_0' = 592170100ab4055c92a269faf579e29e7e453d13549c0dc4f0120fc670ff357d
timeslot = 16
encode(s, eta_0', timeslot)_ = 00000000592170100ab4055c92a269faf579e29e7e453d13549c0dc4f0120fc670ff357d10000000
hash(encoded) = 637f3b10830f888d8c1f427e9566069c4f8cd1539fa9deacfb99d7709663a80c
hashed[:4] = 637f3b10
decode(hashed[:4]) = 272334691
decoded mod 4294966784 + 256= 272334947 

Is that the correct reasoning?

[sourabhniyogi]

We believe we addressed the 2 major issues in 0.6.2.4:

1. ServiceID generation was incorrect -- we now generate 272334947 (see above for our derivation)
2. Incorrect Wrangling of Work Results -- we updated bootstrap to match and hope we can improve this to get this doc correct.

Important: We have temporarily removed the "Transfer" operation in bootstrap service as per @davxy 's suggestion, which temporarily necessitates removing a FULL check in our host write implementation:

We believe a bootstrap operation should have a transfer operation at the end, but maybe for debugging team implementations having 3 host function calls (new, write, transfer) there is a better idea than re-enabling this. Can you suggest one and check if we have solved the Incorrect Wrangling of Work Results problem @davxy @jaymansfield

hostNew() [jam-duna #74 check]
code_hash_ptr=feff0000
  ==> code_hash_ptr=1f2acc37e37dc4f99c3fc50202c92d0c148c6e73ef789a37189221e2b24c46fd
code_len (w8)=235
min_item_gas (w9)=100
min_memo_gas (w10)=100

[jaymansfield]

@sourabhniyogi It's definitely looking a lot better in this version.

Two things:

1. There may be an issue with balances.

In your post state:

Service 0 has a balance of 9999999900.
Service 272334947 has a balance of 100.

I believe this is incorrect since the balance for 272334947 is under it's threshold balance. When creating the new service you may need to set its balance after adding (c,l)↦ [] and not prior.

My implementation ends up with:

Service 0 has a balance of 9999998650.
Service 272334947 has a balance of 1350.

2. We also have a difference in storage keys but I haven't investigated yet to see if its my issue or not.

I end up with a key of 0x81e47a19e6b29b0a65b9591762ce5143ed30d0261e5d24a3201752506b20f15c instead of 0xffffffff00000000000000000000000000000000000000000000000000000000.

[sourabhniyogi]

1. There may be an issue with balances.

In your post state:

Service 0 has a balance of 9999999900. Service 272334947 has a balance of 100.

I believe this is incorrect since the balance for 272334947 is under it's threshold balance. When creating the new service you may need to set its balance after adding (c,l)↦ [] and not prior.
My implementation ends up with:

Service 0 has a balance of 9999998650. Service 272334947 has a balance of 1350.

Hmm. With GP Eq 9.8 $a_t$

computed from

• $B_S$ = 100
• $B_I$ = 10
• $B_L$ = 1

being used for $b$ to initialize:

we believe there are TWO possible values for 272334947 $a_t$

• case 1: a_i = 0, a_o = 0 leads to a_t = 100
• case 2: a_i = 2, a_o = 81 + 1149 = 1230 leads to a_t = 100 + 10 * 2 + 1 * 1230 = 1350

and its unclear which one is the correct one for the new service.

Generally, we'd like to be able to do this:
(a) when something is unambiguous, derive the answer from GP
(b) when something is ambiguous, state that its unclear and improve GP to be 100% unambiguous

This seems to be a case of ambiguity, but probably we missed something -- What did we miss?

But for service 0, we do not have any ambiguity:

• a_i = 2, a_0 = 909 leads to (x_s)_t = 100 + 10 * 2 + 1 * 909 = 1029
• ( x_s )_b = 10000000000

thus s_b > (x_s)_t and we do not have an underflow CASH error in new

case 1: s_b = 10000000000 - 100 = 9999999900
case 2: s_b = 10000000000 - 1350 = 9999998650

2. We also have a difference in storage keys but I haven't investigated yet to see if its my issue or not.

I end up with a key of 0x81e47a19e6b29b0a65b9591762ce5143ed30d0261e5d24a3201752506b20f15c instead of 0xffffffff00000000000000000000000000000000000000000000000000000000.

See #86

ComputeC_sh(s=0, h=0xffffffff00000000000000000000000000000000000000000000000000000000)=00ff00ff00ff00ff000000000000000000000000000000000000000000000000

Here's a log of a large number of other traces

https://github.com/jam-duna/jamtestnet/blob/main/assurances.txt#L9
Ideally you could provide a derivation.

[davxy]

So now looks like you removed all the hostcalls? If yes, maybe you need to at least call the "new" to check that I receive the correct args in the hostcall. Your bootstrap sources now doesn't compile to the blob in accumulate right?

[jaymansfield]

See #86

@sourabhniyogi I was referring to the storage key that is created in the write host call and not the state key for storage.

E4(s)⌢ µko ⋅⋅⋅+kz
0000000000000000 (Service ID is 0, and right now for me µko is pointing to an unset memory position so it results in zeros as well)

H(E4(s)⌢ µko ⋅⋅⋅+kz )
0x81e47a19e6b29b0a65b9591762ce5143ed30d0261e5d24a3201752506b20f15c

[jaymansfield]

So now looks like you removed all the hostcalls? If yes, maybe you need to at least call the "new" to check that I receive the correct args in the hostcall. Your bootstrap sources now doesn't compile to the blob in accumulate right?

When I first ran the latest version I had a similar issue where I ended up in halt with no host calls executed. But I noticed an issue with one of my pvm instructions and after correctly it, the "new" and "write" host calls were performed again.

[davxy]

So now looks like you removed all the hostcalls? If yes, maybe you need to at least call the "new" to check that I receive the correct args in the hostcall. Your bootstrap sources now doesn't compile to the blob in accumulate right?

When I first ran the latest version I had a similar issue where I ended up in halt with no host calls executed. But I noticed an issue with one of my pvm instructions and after correctly it, the "new" and "write" host calls were performed again.

What issue? We're using @koute pvm
Are you aligned to the latest commit: f5b2a03?

Would be very helpful to have a trace from the program start to the point where "new" host call is performed (a pastebin somewhere is fine, just to not bloat too much this discussion).
Even though I'm ABSOLUTELY NOT the PVM guru of our team I can at least see if the trace matches with ours up to some point. Then if we have some strange diff I'll call out @koute as the maximum expert of PVM in our team (and maybe in others as well ;-)

[jaymansfield]

Edit: would be very helpful to have a trace from the program start to the point where "new" host call is performed (a pastebin somewhere is fine, just to not bloat too much this discussion)

Here is a trace from mine of the whole program. First host call is PC 647.
https://gist.github.com/jaymansfield/ce04f45ceefa08d9776e7a2e6c800523

Ignore the gas values shown I think I had it hardcoded to 500 to start to debug something and forgot to switch it back.

[davxy]

@sourabhniyogi @jaymansfield

Alright, from the disassembled blob I can see the HF calls, but we never reach them during execution because of 2 independent problems:

1. The WR reports 101 as gas. But this is exhausted way before reaching the first host call
2. Instruction executed at PC 636 triggers a trap!

633: s1 = s1 + s0                               
      // s1 = 0x0
636: a1 = u32 [s1 + 4294967292]  
    // Load of 4 bytes from 0xfffffffc failed!  
    // TRAP TRIGGERED => bail out
639: a2 = 0x64
642: a3 = 0x64
645: a0 = s0
647: ecalli 9        // NEW Host Call is never reached

From what I can can tell instruction at 636 tries to load in a1 4 bytes from address 0xfffffffc .
This is most certainly due to this code here:

jamtestnet/services/jam-duna/bootstrap/src/main.rs

Lines 147 to 148 in f5b2a03

	let code_length_address: u64 = work_result_address + work_result_length - 4;
	let code_length: u64 = unsafe { ( *(code_length_address as *const u32)).into() };

Where apparently the work_report_address is 0? So maybe is not correctly assigned in the loop above?

@jaymansfield I see from your execution trace that you just continue, probably loading incorrect stuff from 0xfffffffc? Isn't access from that address supposed to trigger a trap?

[jaymansfield]

The WR reports 101 as gas. But this is exhausted way before reaching the first host call

I think this is why I hardcoded the gas limit previously when testing this.

From what I can can tell instruction at 636 tries to load in a1 4 bytes from address 0xfffffffc .

My instruction 636 loads from memory location 4278124587 which exists. Reg 6=4278124591 and immediate=-4 and I end up with a matching code length same as the vector.

[sourabhniyogi]

Creating new issue #90 and closing this one, we will take 48 hours to resolve this trap/gas issue, the storage key issue (our side), general gas computation (our issue) and new a_t 100 vs 1350 update question (asked in GP chat)