Test failure: LR test (Ubuntu 18) nodeos_repeat_transaction_lr_test

[linh2931]

https://github.com/AntelopeIO/leap/actions/runs/3069745720/jobs/4958806080#step:4:53
and
https://github.com/AntelopeIO/leap/actions/runs/3069745720/jobs/4958806080#step:4:3924

2022-09-16T18:04:29.874925   cmd: programs/cleos/cleos --url http://localhost:8892 --wallet-url http://localhost:9899 --no-auto-keosd -v transfer -j --expiration 90 eosio test11111225 1000.0000 SYS test transfer
2022-09-16T18:04:29.965991     ERROR: b'RESPONSE:\n---------------------\nInternal Server Error\n\nUnhandled Exception: 2 timeout_exception: deadline 2022-09-16T18:04:29.953 exceeded by 880us \ndeadline 2022-09-16T18:04:29.953 exceeded by 880us \n    {"d":"2022-09-16T18:04:29.953","t":880}\n    http-0  json.hpp:63 operator()\n\n---------------------\n\x1b[31mError 3200005: http request fail\x1b[0m\n\x1b[33mError Details:\nError code 500\n: Internal Server Error\n\nUnhandled Exception: 2 timeout_exception: deadline 2022-09-16T18:04:29.953 exceeded by 880us \ndeadline 2022-09-16T18:04:29.953 exceeded by 880us \n    {"d":"2022-09-16T18:04:29.953","t":880}\n    http-0  json.hpp:63 operator()\n\n\x1b[0m\nStack Trace:\nhttpc.cpp:301 do_http_call\n'
2022-09-16T18:04:29.966246  ERROR: Exception during funds transfer.  cmd Duration: 0.091 sec.  RESPONSE:
---------------------
Internal Server Error

Unhandled Exception: 2 timeout_exception: deadline 2022-09-16T18:04:29.953 exceeded by 880us 
deadline 2022-09-16T18:04:29.953 exceeded by 880us 
    {"d":"2022-09-16T18:04:29.953","t":880}
    http-0  json.hpp:63 operator()

---------------------
Error 3200005: http request fail
Error Details:
Error code 500
: Internal Server Error

Unhandled Exception: 2 timeout_exception: deadline 2022-09-16T18:04:29.953 exceeded by 880us 
deadline 2022-09-16T18:04:29.953 exceeded by 880us 
    {"d":"2022-09-16T18:04:29.953","t":880}
    http-0  json.hpp:63 operator()


Stack Trace:
httpc.cpp:301 do_http_call

2022-09-16T18:04:29.966490   FAILURE - could not transfer "1000.0000 SYS" from Name: eosio to Name: test11111225
2022-09-16T18:04:29.966716   ERROR: Failed to transfer "1000.0000 SYS" from Name: eosio to Name: test11111225
2022-09-16T18:04:29.967075  Test failed.

[linh2931]

The deadline exception occurred in keosd, as test_keosd_err.log contained the following log:

...
warn  2022-09-16T18:04:14.637 keosd     wallet.cpp:218                save_wallet_file     ] saving wallet to file /__w/leap/leap/build/var/test_wallet_0/./test.wallet
warn  2022-09-16T18:04:14.682 keosd     wallet.cpp:218                save_wallet_file     ] saving wallet to file /__w/leap/leap/build/var/test_wallet_0/./test.wallet
error 2022-09-16T18:04:29.954 http-0    beast_http_session.hpp:316    handle_exception     ] fc::exception: 2       timeout_exception: deadline 2022-09-16T18:04:29.953 exceeded by 880us
deadline 2022-09-16T18:04:29.953 exceeded by 880us
    {"d":"2022-09-16T18:04:29.953","t":880}
    http-0  json.hpp:63 operator()

It is most likely due to deadline reached in string data = fc::json::to_pretty_string( _wallet );

leap/plugins/wallet_plugin/wallet.cpp

Line 220 in e401c23

string data = fc::json::to_pretty_string( _wallet );

As to_pretty_string was called without explicitly specifying a deadline, deadline exception would have not triggered. Some memory corruption could have happed.

[heifner]

I would argue that the exception happened in:
https://github.com/AntelopeIO/leap/blob/main/plugins/http_plugin/include/eosio/http_plugin/common.hpp#L232
at fc::json::to_string.

nodeos is passed --http-max-response-time-ms 990000, while keosd is not passed a high http-max-response-time-ms using the default of 30ms. I would say that it just happened to take longer than 30ms. The fix here is to increase the http-max-response-time-ms on keosd in our tests.

[linh2931]

Thanks @heifner for looking into this and the correction.