search

stakwork / sphinx-key

Lightning hardware signer on ESP32
28 stars 1 forks source link

IO error, kind: InvalidInput, message: "Invalid argument" #133

Closed irriden closed 9 months ago

irriden commented 9 months ago

To reproduce 9d8031d962665732b1c48e7ec9516f6f7ffbe44f:

  1. Start with completely fresh signer (completely erased flash) + broker setup.
  2. Run deploy.sh
  3. Send config to signer.
  4. Signer connects to broker, and immediately crashes as shown further below, at this line:

https://github.com/stakwork/sphinx-key/blob/9d8031d962665732b1c48e7ec9516f6f7ffbe44f/sphinx-key/src/core/lss.rs#L45

To temporarily bypass the error from that point:

  1. cd sphinx-key
  2. cargo clean
  3. ./up.sh

The cargo clean step is the crucial step - without it we go right back to Invalid argument.

SNTP status Reset
SNTP status Reset
SNTP status Reset
SNTP status Completed
I (11189) esp_idf_svc::sntp: Dropped
Completed the time sync, here is the UNIX time: 1696354464
I (11349) sphinx_key: PUBKEY 02bc855fd72bc8f9240917f848651de15614334de1db5ab4eef014fc4e6c187a4f TOKEN ZRxQoB-4ROZ1PtIewNJlZT7NJLUtINmg2NYiV1DtFri1Q9E8NQob8pax1s6zphcKJ7f_eSxZSYO5qkWWtzo1_d9Xok3y
I (11359) sphinx_key::conn::mqtt: make_client with id d918ea5845b9766d49c7119186c7df2e
I (11369) sphinx_key::conn::mqtt: => connect to MQTT at mqtt://192.168.1.82:1883
I (11379) sphinx_key::conn::mqtt: MQTT client started
I (11379) sphinx_key::conn::mqtt: MQTT Listening for messages
I (11389) sphinx_key::conn::mqtt: RECEIVED BeforeConnect MESSAGE
I (11389) sphinx_key: Network set to Regtest
I (11399) sphinx_key: >>>>>>>>>>> blocking forever...
I (11399) sphinx_key: Config { broker: "192.168.1.82:1883", ssid: "Livebox-Suffren", pass: "Suffren2023", network: "regtest" }
I (11589) sphinx_key::periph::led: LED STATUS: ConnectingToMqtt
I (18589) sphinx_key::conn::mqtt: RECEIVED Connected MESSAGE
I (18589) sphinx_key::core::events: BROKER IP AND PORT: 192.168.1.82:1883
I (18589) sphinx_key::core::events: SUBSCRIBE to d918ea5845b9766d49c7119186c7df2e/vls
I (18599) sphinx_key::core::events: SUBSCRIBE to d918ea5845b9766d49c7119186c7df2e/control
I (18609) sphinx_key::conn::mqtt: RECEIVED Subscribed MESSAGE
I (18619) sphinx_key::core::events: SUBSCRIBE to d918ea5845b9766d49c7119186c7df2e/proxy
I (18629) sphinx_key::conn::mqtt: RECEIVED Subscribed MESSAGE
I (18629) sphinx_key::core::events: SUBSCRIBE to d918ea5845b9766d49c7119186c7df2e/init-1-msg
I (18639) sphinx_key::conn::mqtt: RECEIVED Subscribed MESSAGE
I (18649) sphinx_key::core::events: SUBSCRIBE to d918ea5845b9766d49c7119186c7df2e/init-2-msg
I (18649) sphinx_key::core::events: SUBSCRIBE to d918ea5845b9766d49c7119186c7df2e/lss-msg
I (18659) sphinx_key::core::events: SUBSCRIBE to d918ea5845b9766d49c7119186c7df2e/lss-conflict
I (18679) sphinx_key::conn::mqtt: RECEIVED Subscribed MESSAGE
I (18679) sphinx_key::conn::mqtt: RECEIVED Subscribed MESSAGE
I (18689) sphinx_key::conn::mqtt: RECEIVED Subscribed MESSAGE
I (18689) sphinx_key::conn::mqtt: RECEIVED Subscribed MESSAGE
I (20739) sphinx_key::core::lss: init lss start
I (20739) sphinx_key::core::lss: 0
I (20759) sphinx_key::core::lss: 1
I (21639) sphinx_key::core::lss: 2
I (21639) sphinx_key::core::lss: 3
I (21639) sphinx_key::core::lss: 4
I (21659) sphinx_key::core::lss: 5
I (22549) vls_protocol_signer::handler: New node 02bc855fd72bc8f9240917f848651de15614334de1db5ab4eef014fc4e6c187a4f
I (22559) vls_protocol_signer::handler: vls_protocol_signer::handler::RootHandlerBuilder::do_build:: NodeState::summary 02bc: 0 invoices, 0 issued_invoices, 0 payments, excess_amount 0
ERROR Io(Os { code: 22, kind: InvalidInput, message: "Invalid argument" })
E (22619) sphinx_key::core::events: failed to init lss failed to commit
I (22619) wifi:state: run -> init (0)
I (22619) wifi:pm stop, total sleep time: 14758065 us / 17470298 us

I (22619) wifi:<ba-del>idx
I (22629) wifi:new:<11,0>, old:<11,0>, ap:<255,255>, sta:<11,0>, prof:6
E (22639) transport_base: poll_read select error 113, errno = Software caused connection abort, fd = 54
E (22639) mqtt_client: Poll read error: 119, aborting connection
W (22649) sphinx_key::conn::mqtt: RECEIVED Disconnected MESSAGE
I (22699) wifi:flush txq
I (22699) wifi:stop sw txq
I (22699) wifi:lmac stop hw txq
ESP-ROM:esp32c3-api1-20210207
Build:Feb  7 2021
rst:0x3 (RTC_SW_SYS_RST),boot:0xd (SPI_FAST_FLASH_BOOT)
Saved PC:0x40382be8
SPIWP:0xee
mode:DIO, clock div:2
load:0x3fcd5820,len:0x16a8
load:0x403cc710,len:0x968
load:0x403ce710,len:0x2e78
SHA-256 comparison failed:
Calculated: 7afa33309d16e67ad672cc5af6d40153e7e6bef1d2ef34815453565ecfaa1c3d
Expected: 0a07bddd8869b7d5b6213e2f8d69af2997afbcfcb41f8d2a71525b08317e9635
Attempting to boot anyway...
irriden commented 9 months ago

Clarification on how to reproduce: before running deploy.sh at step 2, you need to do a cargo clean inside sphinx-key and factory.

irriden commented 9 months ago

Using deploy.sh, the settings from factory/sdkconfig.defaults are used for the sphinx-key binary. These did not contain the long filename setting, and caused the crash here:

https://github.com/stakwork/sphinx-rs/blob/1db05b95edc8889d68967cc2a91bb6cbee92c76c/signer/src/kvv.rs#L157

Doing a cargo clean and ./up.sh inside sphinx-key reads the settings in sphinx-key/sdkconfig.defaults, which do include the long filename settings. This solved the problem temporarily.

Full solution then was to copy the settings in sphinx-key/sdkconfig.defaults to factory/sdkconfig.defaults.