client/eth/nodeclient_harness_test: First try with new harness fails.

[JoeGruffins]

The first run of tests always seem to fail in a few spots. Probably just needs some more time to sync? Subsequent tests use the same node directory which is probably why this happens on the first run, when the internal node is created.

Some error messages:

...
nodeclient_harness_test.go:438: no receipt at index 0 in block 0x0000000000000000000000000000000000000000000000000000000000000000 for tx 0x4abfbfd098973ea86b65c53ba2e89240129548b2b7b3fba7916444ab12789948
...
--- FAIL: TestAccount (2.52s)
    --- PASS: TestAccount/testAccounts (0.00s)
    --- PASS: TestAccount/testBalance (0.00s)
    --- PASS: TestAccount/testUnlock (0.07s)
    --- PASS: TestAccount/testLock (0.00s)
    --- PASS: TestAccount/testListWallets (0.00s)
    --- PASS: TestAccount/testSendTransaction (1.19s)
    --- FAIL: TestAccount/testTransactionReceipt (1.1

nodeclient_harness_test.go:632: 1 swap ok: receipt error: no receipt at index 0 in block 0x0000000000000000000000000000000000000000000000000000000000000000 for tx 0xe3eff8eb097ef2ab570630a48011e3e5ae063f223019efa1309067321eeb4803
...
--- FAIL: TestContract (127.41s)
    --- PASS: TestContract/testSwap (0.00s)
    --- FAIL: TestContract/testInitiate (1.17s)
    --- PASS: TestContract/testRedeem (63.64s)
    --- PASS: TestContract/testRefund (62.59s)

This last one is another testInitiate failure, but is kind of different than the others and may be something else.

nodeclient_harness_test.go:656: 1 swap ok: unexpected balance change: want 10999999781551 got 10999999646531, diff = 135019

[JoeGruffins]

I'll look into this then.

[chappjc]

Thanks! Much appreciated

[JoeGruffins]

oh wtf

[joe@hyrule harness-ctl]$ ./gamma attach --exec 'eth.getTransaction("0x0dec40b2d89c9f64d456bfe26d64851788ee1a2ef9ccdb1f032a3e0f97a8ce79")'
null
[joe@hyrule harness-ctl]$ ./alpha attach --exec 'eth.getTransaction("0x0dec40b2d89c9f64d456bfe26d64851788ee1a2ef9ccdb1f032a3e0f97a8ce79")'
{
  accessList: [],
  blockHash: "0x938f912605f42380669c36208a3144ea78a3203e549519a510bf0d4ca2006647",
  blockNumber: 430,
  chainId: "0x2a",
  from: "0xdd93b447f7ebca361805ebe056259853f3912e04",
  gas: 135000,
  gasPrice: 2000000007,
  hash: "0x0dec40b2d89c9f64d456bfe26d64851788ee1a2ef9ccdb1f032a3e0f97a8ce79",
  input: "0xa8793f94000000000000000000000000000000000000000000000000000000000000002000000000000000000000000000000000000000000000000000000000000000010000000000000000000000000000000000000000000000000000000061b6a888c95c49f6e2a1097418c8421cefbc5abbed274a60c2e643744fe780a907632dd90000000000000000000000008d83b207674bfd53b418a6e47da148f5bfecc6520000000000000000000000000000000000000000000000000000000077359400",
  maxFeePerGas: 1000000000000,
  maxPriorityFeePerGas: 2000000000,
  nonce: 67,
  r: "0xfaa8d28f565f2da62481b01a8f14258c6fe9d1fbe0cc35367611eda36fd726d6",
  s: "0x97e84dc31228e6bc7289bfd247531170a671ff5688fb1822ac69a68c42805f2",
  to: "0x2f68e723b8989ba1c6a9f03e42f33cb7dc9d606f",
  transactionIndex: 0,
  type: "0x2",
  v: "0x1",
  value: 2000000000
}
[joe@hyrule harness-ctl]$ ./alpha attach --exec 'eth.blockNumber'
556
[joe@hyrule harness-ctl]$ ./gamma attach --exec 'eth.blockNumber'
556
[joe@hyrule harness-ctl]$ ./gamma attach --exec 'eth.getBlockByHash("0x938f912605f42380669c36208a3144ea78a3203e549519a510bf0d4ca2006647")'
{
  baseFeePerGas: "0x7",
  difficulty: "0x2",
  extraData: "0xd883010a0b846765746888676f312e31372e31856c696e757800000000000000d91b4a46b92f27b046d323edc322cb5911156c068208213fd682473346fb57284c7ce4fed8df5b00765dfb646b8a503f466f618588cd483a73dcd8a5b64f5e9401",
  gasLimit: "0x7d30fe",
  gasUsed: "0x20d2f",
  hash: "0x938f912605f42380669c36208a3144ea78a3203e549519a510bf0d4ca2006647",
  logsBloom: "0x00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000",
  miner: "0x0000000000000000000000000000000000000000",
  mixHash: "0x0000000000000000000000000000000000000000000000000000000000000000",
  nonce: "0x0000000000000000",
  number: "0x1ae",
  parentHash: "0x09d518634afcc7ca93bf30793d8b15a4677b76f013eaf3fcedcd5d2f7e0a8b06",
  receiptsRoot: "0x69579c31e9029e251811ebced1224b3df070a1d08544ffb87ebb22f500f66501",
  sha3Uncles: "0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347",
  size: "0x3a2",
  stateRoot: "0xdb0251deff9038620d65b07c40c028c2c5db7922458bed226cf606654e649cce",
  timestamp: "0x61b6a889",
  totalDifficulty: "0x35d",
  transactions: ["0x0dec40b2d89c9f64d456bfe26d64851788ee1a2ef9ccdb1f032a3e0f97a8ce79"],
  transactionsRoot: "0x8681087da9d3360a02e62f17a7b72a62b336ebac3186b0b6885730f1b3353942",
  uncles: []
}

So... sometimes light node can't find txs unless you intentionally pull the block first it seems.

[joe@hyrule harness-ctl]$ ./delta attach --exec 'eth.getTransaction("0x0dec40b2d89c9f64d456bfe26d64851788ee1a2ef9ccdb1f032a3e0f97a8ce79")'
null
[joe@hyrule harness-ctl]$ ./delta attach --exec 'eth.getBlockByHash("0x938f912605f42380669c36208a3144ea78a3203e549519a510bf0d4ca2006647")'
{
  baseFeePerGas: "0x7",
  difficulty: "0x2",
  extraData: "0xd883010a0b846765746888676f312e31372e31856c696e757800000000000000d91b4a46b92f27b046d323edc322cb5911156c068208213fd682473346fb57284c7ce4fed8df5b00765dfb646b8a503f466f618588cd483a73dcd8a5b64f5e9401",
  gasLimit: "0x7d30fe",
  gasUsed: "0x20d2f",
  hash: "0x938f912605f42380669c36208a3144ea78a3203e549519a510bf0d4ca2006647",
  logsBloom: "0x00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000",
  miner: "0x0000000000000000000000000000000000000000",
  mixHash: "0x0000000000000000000000000000000000000000000000000000000000000000",
  nonce: "0x0000000000000000",
  number: "0x1ae",
  parentHash: "0x09d518634afcc7ca93bf30793d8b15a4677b76f013eaf3fcedcd5d2f7e0a8b06",
  receiptsRoot: "0x69579c31e9029e251811ebced1224b3df070a1d08544ffb87ebb22f500f66501",
  sha3Uncles: "0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347",
  size: "0x3a2",
  stateRoot: "0xdb0251deff9038620d65b07c40c028c2c5db7922458bed226cf606654e649cce",
  timestamp: "0x61b6a889",
  totalDifficulty: "0x35d",
  transactions: ["0x0dec40b2d89c9f64d456bfe26d64851788ee1a2ef9ccdb1f032a3e0f97a8ce79"],
  transactionsRoot: "0x8681087da9d3360a02e62f17a7b72a62b336ebac3186b0b6885730f1b3353942",
  uncles: []
}
[joe@hyrule harness-ctl]$ ./delta attach --exec 'eth.getTransaction("0x0dec40b2d89c9f64d456bfe26d64851788ee1a2ef9ccdb1f032a3e0f97a8ce79")'
{
  accessList: [],
  blockHash: "0x938f912605f42380669c36208a3144ea78a3203e549519a510bf0d4ca2006647",
  blockNumber: 430,
  chainId: "0x2a",
  from: "0xdd93b447f7ebca361805ebe056259853f3912e04",
  gas: 135000,
  gasPrice: 2000000007,
  hash: "0x0dec40b2d89c9f64d456bfe26d64851788ee1a2ef9ccdb1f032a3e0f97a8ce79",
  input: "0xa8793f94000000000000000000000000000000000000000000000000000000000000002000000000000000000000000000000000000000000000000000000000000000010000000000000000000000000000000000000000000000000000000061b6a888c95c49f6e2a1097418c8421cefbc5abbed274a60c2e643744fe780a907632dd90000000000000000000000008d83b207674bfd53b418a6e47da148f5bfecc6520000000000000000000000000000000000000000000000000000000077359400",
  maxFeePerGas: 1000000000000,
  maxPriorityFeePerGas: 2000000000,
  nonce: 67,
  r: "0xfaa8d28f565f2da62481b01a8f14258c6fe9d1fbe0cc35367611eda36fd726d6",
  s: "0x97e84dc31228e6bc7289bfd247531170a671ff5688fb1822ac69a68c42805f2",
  to: "0x2f68e723b8989ba1c6a9f03e42f33cb7dc9d606f",
  transactionIndex: 0,
  type: "0x2",
  v: "0x1",
  value: 2000000000
}

How do we make this work if we don't know the block yet. Is this intended I wonder?

[JoeGruffins]

Went ahead and made an issue ethereum/go-ethereum#24101

I think this is contributing to some of the test failures. Not sure why weren't seeing before though. Will wait for their reply to at least to see if this is intended. May even be due to geth updates that this is happeneing now where it wasn't before.

[chappjc]

Hmm, I thought that's what this was all about: ethereum/go-ethereum#19069 (comment)

It will "just work". No extra function is provided, eth.getTransaction works in light mode.

So, I'm surprised too that you're seeing null, but I think buck had reported this too in a different context.

[chappjc]

Maybe it's this race we talked about: #1317 (comment)
Could (*PublicTransactionPoolAPI).GetTransactionByHash need to do these in the opposite order, as we do in (*nodeClient).transactionConfirmations?
@JoeGruffins When eth.getTransaction says null, if you retry does it still say null, no matter how many times you try unless you get the block first? When debugging this it sure looked like the LesApiBackend would end up doing a odr.Retrieve if it didn't find the data already in the local DB: #1317 (comment)
Maybe we get a unit test that hits this null result, set a breakpoint, and try to step through the calls to see where it's coming up empty handed in the go-ethereum code.

[JoeGruffins]

I'll try twice. This bug wouldn't have anything to do with our code if it affects delta and gamma, they are just normal light nodes afaik.

[chappjc]

Yeah, I don't mean our code has the bug, just that a Go test could provide an easy way to step into the geth code handling the request.
We could also attach to the geth instance.

[JoeGruffins]

Is it intended that this doesn't return the error?

dcrdex/client/asset/eth/nodeclient.go

Lines 271 to 274 in fbff9b6

	_, blockHash, _, index, err := n.leth.ApiBackend.GetTransaction(ctx, txHash)
	if err != nil {
	return nil, nil
	}

[chappjc]

It was modeled after the internal/ethapi handler when we ditched the ethclient business for most calls:

https://github.com/ethereum/go-ethereum/blob/72c2c0ae7e2332b08d3e1ebfe5f850a92e26e8a1/internal/ethapi/api.go#L1609-L1621

The reason why they return nil, nil ethereum/go-ethereum#16217, which is because of the RPC spec they have to adhere too.

That doesn't mean it's right for our (nodeClient).transactionReceipt though. Our current callers are clearly assuming nil err means non-nil receipt, so I think we should change it.

[JoeGruffins]

After calling this out I cannot even make it happen again.

[JoeGruffins]

Oh shoo, you were right:

[joe@hyrule harness-ctl]$ ./gamma attach --exec 'eth.getTransaction("0xb2846bb0c1b97c22ff2f886ed0e5ca383e054b5830abdacb7066c1daa14ec7a9")'
null
[joe@hyrule harness-ctl]$ ./gamma attach --exec 'eth.getTransaction("0xb2846bb0c1b97c22ff2f886ed0e5ca383e054b5830abdacb7066c1daa14ec7a9")'
{
  accessList: [],
  blockHash: "0x045666f2a4c7c5e077065b182f97538c93ba935c95ab13476b25c87fbaf3238b",
  blockNumber: 221,
  chainId: "0x2a",
  from: "0xdd93b447f7ebca361805ebe056259853f3912e04",
  gas: 21000,
  gasPrice: 2000000000,
  hash: "0xb2846bb0c1b97c22ff2f886ed0e5ca383e054b5830abdacb7066c1daa14ec7a9",
  input: "0x",
  maxFeePerGas: 2000000000,
  maxPriorityFeePerGas: 2000000000,
  nonce: 45,
  r: "0x640cc950e3a71cc1cb5a487a62edd9b778d178ea24da2fb22de4f6dad23076ea",
  s: "0x4507a46a4f4a1f2d40d2de89039f81fd09ac254b313d67b50c927995614c6ac5",
  to: "0x8d83b207674bfd53b418a6e47da148f5bfecc652",
  transactionIndex: 0,
  type: "0x2",
  v: "0x0",
  value: 1000000000
}

[JoeGruffins]

Closed with

With a light node, you won't always get up-to-date results. It needs to have a server to query about things, and that can't always be guaranteed. Since you're also running with very fast blocks, 1 second between them, the chance that a les client is cannot obtain the requested information in time increases.
I don't think this is an issue in geth, rather "the way things are" due to the nature of light clients.

so... "use full node" lol

Probably @buck54321 has dug around in the geth lightnode code the most, and @chappjc, if you know what exactly is going on with fetching txs. It is able to fetch the tx after you ask for it. Also happens randomly. Seems like a simple race to me... Reposting chapps linked comment #1317 (comment)

Could be a problem with the harness, which is best case. Can try to see if it happens on mainnet at all I guess.

[chappjc]

Ugh. Well leads we have:

• one second period -- too fast?
• we should always "have a server to query things about", so unless the light client loses that connection it should indeed retrieve the txns on demand. If there are transient connectivity issues, maybe... but this seems too flakey.
• The geth code could also have the reversed logic in (*PublicTransactionPoolAPI).GetTransactionByHash. Namely, GetTransaction (finalized/mined tnx) followed by GetPoolTransaction, instead of the other way around

At the end of the day, what's the consequence of pulling a null? In the tests, fail, ok, that's lame, but in reality, retry?

[JoeGruffins]

On geth 1.10.15-stable now and haven't seen this is a while. Maybe fixed?

[JoeGruffins]

I did just see:

=== RUN   TestPeering/testGetCodeAt
    nodeclient_harness_test.go:2168: Contract on chain does not match one in code

[JoeGruffins]

Still not seen in a while. Tempted to close.

[JoeGruffins]

Seems fixed, so closing. I think the last testGetCodeAt failure was fixed with new synced logic in #1630