Payment test fails #1411

Closed
opened 2025-12-28 17:22:54 +00:00 by sami · 4 comments
Owner

Originally created by @roman-khimov on GitHub (Apr 30, 2025).

Current Behavior

https://rest.fs.neo.org/HXSaMJXk2g8C14ht8HSi7BBaiYZ1HeWh2xnWPGQCg4H6/3166-1745943519/index.html#suites/44e11ced39071e8d0cfc11c5b94622ba/dbc5d8a0a60c31dd/

Expected Behavior

Green.

Possible Solution

Fix something.

Steps to Reproduce

Run testcases with master (pre-0.46.0) node.

Context

IR does transfers properly:

debug innerring/settlement.go:240 basic income: transfer was successfully sent {"sender": "NZSjjg82QzeSsxtyx3iz6zoRoMijWMcE1U", "recipient": "NL1H4he1ggRajT1ZVqn23zveMRaH9jDvfh", "amount (GASe-12)": "279396772384", "details": "410200000000000000"}
debug innerring/settlement.go:240 basic income: transfer was successfully sent {"sender": "NZSjjg82QzeSsxtyx3iz6zoRoMijWMcE1U", "recipient": "NL1H4he1ggRajT1ZVqn23zveMRaH9jDvfh", "amount (GASe-12)": "1676380634307", "details": "410300000000000000"}

and alike.

Test also check for balances of user wallet ("Ensure the user wallet balance is charged only once per epoch") and there are correct transfers there:

COMMAND: ./neofs-cli --config /home/runner/work/neofs-node/neofs-node/neofs-testcases/test-run-2025-04-29-15-00-10-473138/env_files/neofs-env-2025-04-29-15-58-35/cli_config_nodjqxqfeb.yml accounting balance --wallet '/home/runner/work/neofs-node/neofs-node/neofs-testcases/test-run-2025-04-29-15-00-10-473138/env_files/neofs-env-2025-04-29-15-58-35/deposit_withdrawal_test_wallet_kaioqthfes' --rpc-endpoint 'localhost:59203' --address 'NZSjjg82QzeSsxtyx3iz6zoRoMijWMcE1U'
RETCODE: 0

STDOUT:
91.45628714

Then

COMMAND: ./neofs-cli --config /home/runner/work/neofs-node/neofs-node/neofs-testcases/test-run-2025-04-29-15-00-10-473138/env_files/neofs-env-2025-04-29-15-58-35/cli_config_nodjqxqfeb.yml accounting balance --wallet '/home/runner/work/neofs-node/neofs-node/neofs-testcases/test-run-2025-04-29-15-00-10-473138/env_files/neofs-env-2025-04-29-15-58-35/deposit_withdrawal_test_wallet_kaioqthfes' --rpc-endpoint 'localhost:59203' --address 'NZSjjg82QzeSsxtyx3iz6zoRoMijWMcE1U'
RETCODE: 0

STDOUT:
88.66231942

But for storage node (" Ensure the storage node balance is debited only once per epoch") test seems to be using some wrong address:

COMMAND: ./neofs-cli --config /home/runner/work/neofs-node/neofs-node/neofs-testcases/test-run-2025-04-29-15-00-10-473138/env_files/neofs-env-2025-04-29-15-58-35/sn_1_gffvdmixws/sn_1_cli_config_irckuusoeh.yml accounting balance --wallet '/home/runner/work/neofs-node/neofs-node/neofs-testcases/test-run-2025-04-29-15-00-10-473138/env_files/neofs-env-2025-04-29-15-58-35/sn_1_gffvdmixws/sn_1_wallet_zfxphluuzo' --rpc-endpoint 'localhost:59203' --address 'NQiRkviaJYi5VeaAqD6pYkh61BWVkqxTuS'
RETCODE: 0

STDOUT:
0

Theoretically, it can be an IR issue (wrong address there), but it doesn't seem to be likely.

Regression

Unknown.

Originally created by @roman-khimov on GitHub (Apr 30, 2025). ## Current Behavior https://rest.fs.neo.org/HXSaMJXk2g8C14ht8HSi7BBaiYZ1HeWh2xnWPGQCg4H6/3166-1745943519/index.html#suites/44e11ced39071e8d0cfc11c5b94622ba/dbc5d8a0a60c31dd/ ## Expected Behavior Green. ## Possible Solution Fix something. ## Steps to Reproduce Run testcases with master (pre-0.46.0) node. ## Context IR does transfers properly: > debug innerring/settlement.go:240 basic income: transfer was successfully sent {"sender": "NZSjjg82QzeSsxtyx3iz6zoRoMijWMcE1U", "recipient": "NL1H4he1ggRajT1ZVqn23zveMRaH9jDvfh", "amount (GASe-12)": "279396772384", "details": "410200000000000000"} > debug innerring/settlement.go:240 basic income: transfer was successfully sent {"sender": "NZSjjg82QzeSsxtyx3iz6zoRoMijWMcE1U", "recipient": "NL1H4he1ggRajT1ZVqn23zveMRaH9jDvfh", "amount (GASe-12)": "1676380634307", "details": "410300000000000000"} and alike. Test also check for balances of user wallet ("Ensure the user wallet balance is charged only once per epoch") and there are correct transfers there: > COMMAND: ./neofs-cli --config /home/runner/work/neofs-node/neofs-node/neofs-testcases/test-run-2025-04-29-15-00-10-473138/env_files/neofs-env-2025-04-29-15-58-35/cli_config_nodjqxqfeb.yml accounting balance --wallet '/home/runner/work/neofs-node/neofs-node/neofs-testcases/test-run-2025-04-29-15-00-10-473138/env_files/neofs-env-2025-04-29-15-58-35/deposit_withdrawal_test_wallet_kaioqthfes' --rpc-endpoint 'localhost:59203' --address 'NZSjjg82QzeSsxtyx3iz6zoRoMijWMcE1U' RETCODE: 0 > > STDOUT: > 91.45628714 Then > COMMAND: ./neofs-cli --config /home/runner/work/neofs-node/neofs-node/neofs-testcases/test-run-2025-04-29-15-00-10-473138/env_files/neofs-env-2025-04-29-15-58-35/cli_config_nodjqxqfeb.yml accounting balance --wallet '/home/runner/work/neofs-node/neofs-node/neofs-testcases/test-run-2025-04-29-15-00-10-473138/env_files/neofs-env-2025-04-29-15-58-35/deposit_withdrawal_test_wallet_kaioqthfes' --rpc-endpoint 'localhost:59203' --address 'NZSjjg82QzeSsxtyx3iz6zoRoMijWMcE1U' > RETCODE: 0 > > STDOUT: > 88.66231942 But for storage node (" Ensure the storage node balance is debited only once per epoch") test seems to be using some wrong address: > COMMAND: ./neofs-cli --config /home/runner/work/neofs-node/neofs-node/neofs-testcases/test-run-2025-04-29-15-00-10-473138/env_files/neofs-env-2025-04-29-15-58-35/sn_1_gffvdmixws/sn_1_cli_config_irckuusoeh.yml accounting balance --wallet '/home/runner/work/neofs-node/neofs-node/neofs-testcases/test-run-2025-04-29-15-00-10-473138/env_files/neofs-env-2025-04-29-15-58-35/sn_1_gffvdmixws/sn_1_wallet_zfxphluuzo' --rpc-endpoint 'localhost:59203' --address 'NQiRkviaJYi5VeaAqD6pYkh61BWVkqxTuS' > RETCODE: 0 > > STDOUT: > 0 Theoretically, it can be an IR issue (wrong address there), but it doesn't seem to be likely. ## Regression Unknown.
sami 2025-12-28 17:22:54 +00:00
Author
Owner

@evgeniiz321 commented on GitHub (May 12, 2025):

@roman-khimov it is also reproduced locally 10/10, I see in IR logs a lot of transfers to SN address -

debug   alphabet/process_emit.go:83     sent gas to storage node        {"receiver": "Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT", "amount": 250000000}
debug   innerring/settlement.go:240     basic income: transfer was successfully sent    {"sender": "NL1H4he1ggRajT1ZVqn23zveMRaH9jDvfh", "recipient": "Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT", "amount (GASe-12)": "17788261175145", "details": "421800000000000000"}
debug   alphabet/process_emit.go:83     sent gas to storage node        {"receiver": "Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT", "amount": 250000000}
debug   innerring/settlement.go:240     basic income: transfer was successfully sent    {"sender": "NL1H4he1ggRajT1ZVqn23zveMRaH9jDvfh", "recipient": "Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT", "amount (GASe-12)": "18719583749760", "details": "421900000000000000"}
debug   alphabet/process_emit.go:83     sent gas to storage node        {"receiver": "Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT", "amount": 250000000}
debug   alphabet/process_emit.go:83     sent gas to storage node        {"receiver": "Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT", "amount": 250000000}
debug   innerring/settlement.go:240     basic income: transfer was successfully sent    {"sender": "NL1H4he1ggRajT1ZVqn23zveMRaH9jDvfh", "recipient": "Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT", "amount (GASe-12)": "20582228898990", "details": "421b00000000000000"}
debug   alphabet/process_emit.go:83     sent gas to storage node        {"receiver": "Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT", "amount": 250000000}
debug   innerring/settlement.go:240     basic income: transfer was successfully sent    {"sender": "NL1H4he1ggRajT1ZVqn23zveMRaH9jDvfh", "recipient": "Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT", "amount (GASe-12)": "21513551473605", "details": "421c00000000000000"}
debug   alphabet/process_emit.go:83     sent gas to storage node        {"receiver": "Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT", "amount": 250000000}
debug   innerring/settlement.go:240     basic income: transfer was successfully sent    {"sender": "NL1H4he1ggRajT1ZVqn23zveMRaH9jDvfh", "recipient": "Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT", "amount (GASe-12)": "22444874048220", "details": "421d00000000000000"}

but accounting balance shows only one value (doesn't change between epochs at all - i checked it during like 10 epochs, see the address Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT is the same as in IR logs):

./neofs-cli --config /Users/evgeniiz/Projects/neofs-testcases-nspcc/neofs-testcases/test-run-2025-05-12-17-23-13-744903/env_files/neofs-env-2025-05-12-17-23-14/sn_3_qhqurfxgqh/sn_3_cli_config_seypqshsvy.yml accounting balance --wallet '/Users/evgeniiz/Projects/neofs-testcases-nspcc/neofs-testcases/test-run-2025-05-12-17-23-13-744903/env_files/neofs-env-2025-05-12-17-23-14/sn_3_qhqurfxgqh/sn_3_wallet_nvrvbeoemc' --rpc-endpoint 'localhost:52154' --address 'Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT'
0.27939677

maybe some kind of a caching issue? and yes, it happens only on the latest node from master. Prev version - v0.45.0 is ok.

@evgeniiz321 commented on GitHub (May 12, 2025): @roman-khimov it is also reproduced locally 10/10, I see in IR logs a lot of transfers to SN address - ``` debug alphabet/process_emit.go:83 sent gas to storage node {"receiver": "Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT", "amount": 250000000} debug innerring/settlement.go:240 basic income: transfer was successfully sent {"sender": "NL1H4he1ggRajT1ZVqn23zveMRaH9jDvfh", "recipient": "Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT", "amount (GASe-12)": "17788261175145", "details": "421800000000000000"} debug alphabet/process_emit.go:83 sent gas to storage node {"receiver": "Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT", "amount": 250000000} debug innerring/settlement.go:240 basic income: transfer was successfully sent {"sender": "NL1H4he1ggRajT1ZVqn23zveMRaH9jDvfh", "recipient": "Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT", "amount (GASe-12)": "18719583749760", "details": "421900000000000000"} debug alphabet/process_emit.go:83 sent gas to storage node {"receiver": "Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT", "amount": 250000000} debug alphabet/process_emit.go:83 sent gas to storage node {"receiver": "Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT", "amount": 250000000} debug innerring/settlement.go:240 basic income: transfer was successfully sent {"sender": "NL1H4he1ggRajT1ZVqn23zveMRaH9jDvfh", "recipient": "Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT", "amount (GASe-12)": "20582228898990", "details": "421b00000000000000"} debug alphabet/process_emit.go:83 sent gas to storage node {"receiver": "Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT", "amount": 250000000} debug innerring/settlement.go:240 basic income: transfer was successfully sent {"sender": "NL1H4he1ggRajT1ZVqn23zveMRaH9jDvfh", "recipient": "Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT", "amount (GASe-12)": "21513551473605", "details": "421c00000000000000"} debug alphabet/process_emit.go:83 sent gas to storage node {"receiver": "Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT", "amount": 250000000} debug innerring/settlement.go:240 basic income: transfer was successfully sent {"sender": "NL1H4he1ggRajT1ZVqn23zveMRaH9jDvfh", "recipient": "Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT", "amount (GASe-12)": "22444874048220", "details": "421d00000000000000"} ``` but accounting balance shows only one value (doesn't change between epochs at all - i checked it during like 10 epochs, see the address Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT is the same as in IR logs): ``` ./neofs-cli --config /Users/evgeniiz/Projects/neofs-testcases-nspcc/neofs-testcases/test-run-2025-05-12-17-23-13-744903/env_files/neofs-env-2025-05-12-17-23-14/sn_3_qhqurfxgqh/sn_3_cli_config_seypqshsvy.yml accounting balance --wallet '/Users/evgeniiz/Projects/neofs-testcases-nspcc/neofs-testcases/test-run-2025-05-12-17-23-13-744903/env_files/neofs-env-2025-05-12-17-23-14/sn_3_qhqurfxgqh/sn_3_wallet_nvrvbeoemc' --rpc-endpoint 'localhost:52154' --address 'Nf1jX17eFH8i6K43bwQhSQdxY1owsa9gpT' 0.27939677 ``` maybe some kind of a caching issue? and yes, it happens only on the latest node from master. Prev version - v0.45.0 is ok.
Author
Owner

@evgeniiz321 commented on GitHub (May 12, 2025):

Suspicious logs from IR:

debug	client/notary.go:522	notary request invoked	{"method": "transferX", "valid_until_block": 1700, "tx_hash": "5da9466e09b730595a501e375f467021b88ae87820f9aa31fc912863325ba0a6", "fallback_hash": "04693c82cc6bf7e6a9fef14ab2b7507da88aa3238dff64dccf23d8b93ee40954"}
warn	core/blockchain.go:1766	contract invocation failed	{"tx": "5da9466e09b730595a501e375f467021b88ae87820f9aa31fc912863325ba0a6", "block": 1591, "error": "at instruction 1348 (SYSCALL): System.Runtime.Log failed: insufficient amount of gas"}
...
error	rpcsrv/server.go:3202	Error encountered with rpc request	{"code": -32603, "cause": "max session capacity reached", "method": "invokefunction", "params": "[74bde06d81add4863409470b08198d4636af3429 listNodes ]"}

@evgeniiz321 commented on GitHub (May 12, 2025): Suspicious logs from IR: ``` debug client/notary.go:522 notary request invoked {"method": "transferX", "valid_until_block": 1700, "tx_hash": "5da9466e09b730595a501e375f467021b88ae87820f9aa31fc912863325ba0a6", "fallback_hash": "04693c82cc6bf7e6a9fef14ab2b7507da88aa3238dff64dccf23d8b93ee40954"} warn core/blockchain.go:1766 contract invocation failed {"tx": "5da9466e09b730595a501e375f467021b88ae87820f9aa31fc912863325ba0a6", "block": 1591, "error": "at instruction 1348 (SYSCALL): System.Runtime.Log failed: insufficient amount of gas"} ... error rpcsrv/server.go:3202 Error encountered with rpc request {"code": -32603, "cause": "max session capacity reached", "method": "invokefunction", "params": "[74bde06d81add4863409470b08198d4636af3429 listNodes ]"} ```
Author
Owner

@roman-khimov commented on GitHub (May 13, 2025):

Still doesn't work.
https://rest.fs.neo.org/HXSaMJXk2g8C14ht8HSi7BBaiYZ1HeWh2xnWPGQCg4H6/3214-1747087432/index.html#suites/44e11ced39071e8d0cfc11c5b94622ba/9ddcfd5081e4aca/ from #3339:

debug	client/notary.go:521	notary request invoked	{"method": "transferX", "valid_until_block": 300, "tx_hash": "865b86f27ec29bba88a11685170283bc3ea3a64a4dc9c0492658e726bf53ef22", "fallback_hash": "3bf8d17a4b49a08f4eb6ebed58c11b124ebb2c4f01a512ece8dccff1c8129576"}
debug	innerring/settlement.go:240	basic income: transfer was successfully sent	{"sender": "NPBzbkvZUcWjyMNmiQr8hXGg1E7jjHxkqe", "recipient": "NL1H4he1ggRajT1ZVqn23zveMRaH9jDvfh", "amount (GASe-12)": "558793544769", "details": "410300000000000000"}
...
info	dbft@v0.3.3-0.20250321140139-7462b47e4d2d/check.go:130	approving block	{"height": 215, "hash": "18fee74d3a667d34d996c9c51c04deb25d440df6caec5e776cf3af7437881e0c", "tx_count": 1, "merkle": "22ef53bf26e7582649c0c94d4aa6a33ebc8302178516a188ba9bc27ef2865b86", "prev": "724314ad2834a456b602cfbf14233d469710e2c250a0bc5fa75cdb5ec364cda4"}
debug	core/blockchain.go:1669	done processing headers	{"headerIndex": 215, "blockHeight": 214, "took": 0.00013458}
info	runtime/engine.go:151	runtime log	{"tx": "865b86f27ec29bba88a11685170283bc3ea3a64a4dc9c0492658e726bf53ef22", "script": "d733d71584323c07cc3db6245fcfdfe42a44c560", "msg": "successfully transferred assets"}

It's a successful transferX.

@roman-khimov commented on GitHub (May 13, 2025): Still doesn't work. https://rest.fs.neo.org/HXSaMJXk2g8C14ht8HSi7BBaiYZ1HeWh2xnWPGQCg4H6/3214-1747087432/index.html#suites/44e11ced39071e8d0cfc11c5b94622ba/9ddcfd5081e4aca/ from #3339: ``` debug client/notary.go:521 notary request invoked {"method": "transferX", "valid_until_block": 300, "tx_hash": "865b86f27ec29bba88a11685170283bc3ea3a64a4dc9c0492658e726bf53ef22", "fallback_hash": "3bf8d17a4b49a08f4eb6ebed58c11b124ebb2c4f01a512ece8dccff1c8129576"} debug innerring/settlement.go:240 basic income: transfer was successfully sent {"sender": "NPBzbkvZUcWjyMNmiQr8hXGg1E7jjHxkqe", "recipient": "NL1H4he1ggRajT1ZVqn23zveMRaH9jDvfh", "amount (GASe-12)": "558793544769", "details": "410300000000000000"} ... info dbft@v0.3.3-0.20250321140139-7462b47e4d2d/check.go:130 approving block {"height": 215, "hash": "18fee74d3a667d34d996c9c51c04deb25d440df6caec5e776cf3af7437881e0c", "tx_count": 1, "merkle": "22ef53bf26e7582649c0c94d4aa6a33ebc8302178516a188ba9bc27ef2865b86", "prev": "724314ad2834a456b602cfbf14233d469710e2c250a0bc5fa75cdb5ec364cda4"} debug core/blockchain.go:1669 done processing headers {"headerIndex": 215, "blockHeight": 214, "took": 0.00013458} info runtime/engine.go:151 runtime log {"tx": "865b86f27ec29bba88a11685170283bc3ea3a64a4dc9c0492658e726bf53ef22", "script": "d733d71584323c07cc3db6245fcfdfe42a44c560", "msg": "successfully transferred assets"} ``` It's a successful `transferX`.
Author
Owner

@roman-khimov commented on GitHub (May 13, 2025):

"sender": "NPBzbkvZUcWjyMNmiQr8hXGg1E7jjHxkqe", "recipient": "NL1H4he1ggRajT1ZVqn23zveMRaH9jDvfh"

$ ./bin/neo-go util convert NL1H4he1ggRajT1ZVqn23zveMRaH9jDvfh
Address to BE ScriptHash        0101010101010101010101010101010101010101
Address to LE ScriptHash        0101010101010101010101010101010101010101

Hmm.

@roman-khimov commented on GitHub (May 13, 2025): > "sender": "NPBzbkvZUcWjyMNmiQr8hXGg1E7jjHxkqe", "recipient": "NL1H4he1ggRajT1ZVqn23zveMRaH9jDvfh" ``` $ ./bin/neo-go util convert NL1H4he1ggRajT1ZVqn23zveMRaH9jDvfh Address to BE ScriptHash 0101010101010101010101010101010101010101 Address to LE ScriptHash 0101010101010101010101010101010101010101 ``` Hmm.
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
nspcc-dev/neofs-node#1411
No description provided.