Holofuel-init fails with an error

[peeech]

holofuel-init.service fails on reserve controller with the following error:

Sep 27 07:42:21 devNet-reserve-controller systemd[1]: Starting holofuel-init.service...
Sep 27 07:42:21 devNet-reserve-controller holofuel_init[30229]: Sep 27 07:42:21.815  INFO holofuel_init: Start initializing the holofuel instance
Sep 27 07:42:21 devNet-reserve-controller holofuel_init[30229]: Sep 27 07:42:21.817 DEBUG connect{url=Url2 { url: "ws://localhost:42233/" }}: holochain_websocket: Client connected
Sep 27 07:42:21 devNet-reserve-controller holofuel_init[30229]: Sep 27 07:42:21.817 TRACE connect{url=Url2 { url: "ws://localhost:42233/" }}:create_ends:run:run_to_socket: holochain_websocket::websocket: starting sending external socket
Sep 27 07:42:21 devNet-reserve-controller holofuel_init[30229]: Sep 27 07:42:21.817 TRACE connect{url=Url2 { url: "ws://localhost:42233/" }}:create_ends:run:run_from_socket: holochain_websocket::websocket: starting receiving from external socket
Sep 27 07:42:22 devNet-reserve-controller holofuel_init[30229]: Sep 27 07:42:22.596 TRACE request{msg=AppInfo { installed_app_id: "holofuel:0_3_1::a4ae21f9-a982-4235-98a6-d5ac1991e793" }}: holochain_websocket::websocket_sender: Sending
Sep 27 07:42:22 devNet-reserve-controller holofuel_init[30229]: Sep 27 07:42:22.596 TRACE request{msg=AppInfo { installed_app_id: "holofuel:0_3_1::a4ae21f9-a982-4235-98a6-d5ac1991e793" }}: holochain_websocket::websocket_sender: Sent
Sep 27 07:42:22 devNet-reserve-controller holofuel_init[30229]: Sep 27 07:42:22.596 TRACE connect{url=Url2 { url: "ws://localhost:42233/" }}:create_ends:run:run_to_socket: holochain_websocket::websocket: sending_msg=Request({"type":{"app_info":null},"data":{"installed_app_id":"holofuel:0_3_1::a4ae21f9-a982-4235-98a6-d5ac1991e793"}}, RegisterResponse { respond: Sender { inner: Some(Inner { state: State { is_complete: false, is_closed: false, is_rx_task_set: false, is_tx_task_set: false } }) } }, Sender { inner: Some(Inner { state: State { is_complete: false, is_closed: false, is_rx_task_set: true, is_tx_task_set: false } }) })
Sep 27 07:42:22 devNet-reserve-controller holofuel_init[30229]: Sep 27 07:42:22.597 TRACE connect{url=Url2 { url: "ws://localhost:42233/" }}:create_ends:run:run_from_socket: holochain_websocket::websocket: received_msg=Binary([131, 164, 116, 121, 112, 101, 168, 114, 101, 115, 112, 111, 110, 115, 101, 162, 105, 100, 0, 164, 100, 97, 116, 97, 196, 114, 130, 164, 116, 121, 112, 101, 165, 101, 114, 114, 111, 114, 164, 100, 97, 116, 97, 130, 164, 116, 121, 112, 101, 175, 100, 101, 115, 101, 114, 105, 97, 108, 105, 122, 97, 116, 105, 111, 110, 164, 100, 97, 116, 97, 217, 68, 66, 121, 116, 101, 115, 40, 68, 101, 115, 101, 114, 105, 97, 108, 105, 122, 101, 40, 34, 105, 110, 118, 97, 108, 105, 100, 32, 116, 121, 112, 101, 58, 32, 109, 97, 112, 44, 32, 101, 120, 112, 101, 99, 116, 101, 100, 32, 118, 97, 114, 105, 97, 110, 116, 32, 105, 100, 101, 110, 116, 105, 102, 105, 101, 114, 34, 41, 41])
Sep 27 07:42:22 devNet-reserve-controller holofuel_init[30229]: Sep 27 07:42:22.597 TRACE connect{url=Url2 { url: "ws://localhost:42233/" }}:create_ends:run:run_from_socket: holochain_websocket::websocket_sender: sending_resp=Some({"type":"error","data":{"type":"deserialization","data":"Bytes(Deserialize(\"invalid type: map, expected variant identifier\"))"}})
Sep 27 07:42:22 devNet-reserve-controller holofuel_init[30229]: Sep 27 07:42:22.597 TRACE holochain_websocket::websocket_sender: Removed stale response on drop
Sep 27 07:42:22 devNet-reserve-controller holofuel_init[30229]: Sep 27 07:42:22.597 TRACE connect{url=Url2 { url: "ws://localhost:42233/" }}:create_ends:run:run_from_socket: holochain_websocket::websocket: exiting receiving from external socket
Sep 27 07:42:22 devNet-reserve-controller holofuel_init[30229]: Error: WebsocketError(SerializedBytesError(Deserialize("wrong msgpack marker FixStr(5)")))
Sep 27 07:42:22 devNet-reserve-controller systemd[1]: holofuel-init.service: Main process exited, code=exited, status=1/FAILURE
Sep 27 07:42:22 devNet-reserve-controller systemd[1]: holofuel-init.service: Failed with result 'exit-code'.
Sep 27 07:42:22 devNet-reserve-controller systemd[1]: Failed to start holofuel-init.service.
Sep 27 07:42:22 devNet-reserve-controller systemd[1]: holofuel-init.service: Consumed 10ms CPU time, received 541B IP traffic, sent 703B IP traffic.

[peeech]

This error is present on both devNet and qaNet

[peeech]

So the problem lies in a fact that deserializer is expecting a different type than it is receiving: (\"invalid type: map, expected variant identifier\").

It seems that app_info request made here is processed by holochain's holochain_websocket crate v0.2.1.

Trace shows that the request is made ( see sending_msg=Request) and then while processing the response inside of the holochain_websocket an error is generated (see sending_resp=Some).

So for me the explanation is that holochain_websocket v0.2.1 used in latest holofuel-init is not compatible with the version of holochain that is running on reserve-controller. As a consequence holochain_websocket crate is not able to process response from a call to .app_info() method.

[peeech]

Reserve controller is following develop branch of holo-nixpkgs. Holochain version installed is holochain 0.2.2-beta-rc.1.