search

locka99 / opcua

A client and server implementation of the OPC UA specification written in Rust
Mozilla Public License 2.0
499 stars 131 forks source link

Panic: 'MessageQueue::send_message should never be called before make_request_channel' #279

Open abdelhaksam opened 1 year ago

abdelhaksam commented 1 year ago

I encountered a panic using the opcua simple-client example when trying to reconnect to an OPC UA server after it goes offline. I tried running the app without an active OPC UA server, then activating it without any issues.

Steps to Reproduce:

  1. Start the simple-client application and establish a connection to an OPC UA device.
  2. Simulate a disconnection of the OPC UA server device.
  3. Simulate the restart of the device.
  4. The program crashes when it attempts to reconnect to the device.

Expected Behavior: The application should successfully reconnect to the OPC UA device without panicking, allowing the data exchange to resume as intended.

Actual Behavior: Upon attempting to reconnect to the OPC UA device, a panic is triggered in the MessageQueue::send_message function, resulting in a program crash.

Additional Information: Logs:

2023-07-08T15:33:06.464924300+01:00 DEBUG opcua::client::session::session_state - async_publish is acknowledging subscription acknowledgements with sequence nrs [12]
2023-07-08T15:33:06.465459800+01:00 DEBUG opcua::client::session::session_state - async_publish, request sent with handle 18
2023-07-08T15:33:06.465799500+01:00 DEBUG opcua::client::message_queue - Request 18 was processed by the server
2023-07-08T15:33:06.666488600+01:00 DEBUG opcua::client::message_queue - Response to Request 18 has been stored
2023-07-08T15:33:06.679197400+01:00 DEBUG opcua::client::session::session_state - ns=1;g=6f600197-760e-cf4d-bd2e-4faeeb11db1c Processing 1 async messages
2023-07-08T15:33:06.679672500+01:00 DEBUG opcua::client::session::session_state - ns=1;g=6f600197-760e-cf4d-bd2e-4faeeb11db1c handle_async_response
2023-07-08T15:33:06.680004800+01:00 DEBUG opcua::client::session::session_state - ns=1;g=6f600197-760e-cf4d-bd2e-4faeeb11db1c Service fault received with BadSessionClosed error code
2023-07-08T15:33:06.680349800+01:00 DEBUG opcua::client::session::session_state - Session was closed with status = BadSessionClosed
Session has been closed, status = BadSessionClosed
2023-07-08T15:33:06.697870900+01:00 DEBUG opcua::client::comms::tcp_transport - Read loop finished, connection state = Processing
2023-07-08T15:33:06.698425800+01:00 INFO opcua::client::comms::tcp_transport - ReadState has dropped
2023-07-08T15:33:06.699039500+01:00 INFO opcua::client::comms::tcp_transport - WriteState has dropped
2023-07-08T15:33:06.699607900+01:00 DEBUG opcua::client::comms::tcp_transport - Closing connection because the read loop terminated
2023-07-08T15:33:06.699946600+01:00 DEBUG opcua::client::session::session_state - Session was closed with status = Good
Session has been closed, status = Good
2023-07-08T15:33:06.709085400+01:00 INFO opcua::client::session_retry_policy - Retry retriggered by policy
2023-07-08T15:33:06.709766100+01:00 INFO opcua::client::session::session - Retrying to reconnect to server...
2023-07-08T15:33:06.710274+01:00 INFO opcua::client::session::session - Connect
2023-07-08T15:33:06.711805600+01:00 INFO opcua::client::session::session - Security policy = None
2023-07-08T15:33:06.712315700+01:00 INFO opcua::client::session::session - Security mode = None
2023-07-08T15:33:06.714195100+01:00 DEBUG opcua::client::comms::tcp_transport - Creating a connection task to connect to [::1]:48040 with url opc.tcp://localhost:48040/
2023-07-08T15:33:08.761768+01:00 ERROR opcua::client::comms::tcp_transport - Could not connect to host [::1]:48040, Os { code: 10061, kind: ConnectionRefused, message: "Aucune connexion n’a pu être établie car l’ordinateur cible l’a expressément refusée." }
2023-07-08T15:33:08.763501600+01:00 DEBUG opcua::client::session::session_state - Session was closed with status = BadCommunicationError
Session has been closed, status = BadCommunicationError
2023-07-08T15:33:08.764255800+01:00 WARN opcua::client::session::session - session:3 Reconnect was unsuccessful, retries = 1
2023-07-08T15:33:08.767081100+01:00 INFO opcua::client::session::session - Session activity timer is terminating
2023-07-08T15:33:08.767641900+01:00 INFO opcua::client::session::session - Session activity timer task is finished
2023-07-08T15:33:08.767970300+01:00 DEBUG opcua::core::runtime - deregistering component session-activity-thread-ThreadId(1)
2023-07-08T15:33:08.768494900+01:00 INFO opcua::client::session::session - Session activity timer is terminating
2023-07-08T15:33:08.769119200+01:00 INFO opcua::client::session::session - Subscription activity timer task is finished
2023-07-08T15:33:08.769583100+01:00 DEBUG opcua::core::runtime - deregistering component subscription-activity-thread-ThreadId(1)
2023-07-08T15:33:16.718284500+01:00 INFO opcua::client::session_retry_policy - Retry retriggered by policy
2023-07-08T15:33:16.718738900+01:00 INFO opcua::client::session::session - Retrying to reconnect to server...
2023-07-08T15:33:16.719398500+01:00 INFO opcua::client::session::session_state - SessionState has dropped
2023-07-08T15:33:16.720019700+01:00 INFO opcua::client::session::session - Connect
2023-07-08T15:33:16.722244+01:00 INFO opcua::client::session::session - Security policy = None
2023-07-08T15:33:16.722987400+01:00 INFO opcua::client::session::session - Security mode = None
2023-07-08T15:33:16.725367300+01:00 DEBUG opcua::client::comms::tcp_transport - Creating a connection task to connect to [::1]:48040 with url opc.tcp://localhost:48040/
2023-07-08T15:33:16.727951500+01:00 DEBUG opcua::client::session::session - session:4 open_secure_channel
2023-07-08T15:33:16.728353400+01:00 INFO opcua::client::session::session_state - Making secure channel request
2023-07-08T15:33:16.728889100+01:00 INFO opcua::client::session::session_state - security_mode = None
2023-07-08T15:33:16.729416+01:00 INFO opcua::client::session::session_state - security_policy = None
thread '<unnamed>' panicked at 'MessageQueue::send_message should never be called before make_request_channel', C:\Users\FUJITSU-RMB\.cargo\registry\src\index.crates.io-6f17d22bba15001f\opcua-0.11.0\src\client\message_queue.rs:57:14

Rust version: rustc 1.70.0 Opcua crate version: 0.11 Operating system: Windows 10 OPC UA Server : UACppServer

abdelhaksam commented 1 year ago

Possible duplicate of #256 Follow up : https://github.com/locka99/opcua/issues/256#issuecomment-1634151438