Client disconnects when using a cancelled context

[aschiffmann]

I accidentally used a cancelled context for a call to opcua.Client.Write(ctx..) which obviously made that write request fail. However it also had the side effect that the client connection was lost and automatically reconnected, during which all my other write and read request also failed with the error

The operation could not complete because the client is not connected to the server. StatusBadServerNotConnected (0x800D0000)

Additionally all subscription got notfied again with unchanged values due to the reconnect.

In my opinion those are quite severe consequences when using a cancelled context which should only fail that single request

I used v0.8.0 and here is the debug log of an example:

debug: secure_channel.go:1050 uasc 4/1844: send *ua.ReadRequest with 1242 bytes debug: conn.go:388 uacp 4: recv MSGF with 347 bytes debug: secure_channel.go:350 uasc 4/1844: recv MSGF with 347 bytes debug: secure_channel.go:289 uasc 4/1844: recv *ua.ReadResponse debug: secure_channel.go:304 uasc 4/1844: sending *ua.ReadResponse to handler

---here the request with a cancelled context is executed

debug: secure_channel_instance.go:89 got sequence number 1845 debug: secure_channel_instance.go:89 got sequence number 1846 debug: secure_channel_instance.go:89 got sequence number 1847 debug: secure_channel.go:1050 uasc 4/1847: send *ua.WriteRequest with 163 bytes debug: secure_channel_instance.go:89 got sequence number 1848 debug: secure_channel.go:1050 uasc 4/1848: send *ua.WriteRequest with 165 bytes debug: conn.go:388 uacp 4: recv ERRF with 16 bytes debug: secure_channel.go:329 uasc 4: readChunk EOF debug: client: monitor: disconnected debug: client: monitor: auto-reconnecting debug: client: monitor: action: createSecureChannel debug: conn.go:221 uacp 4: close debug: secure_channel.go:1180 uasc 4: Close() debug: client: monitor: trying to recreate secure channel debug: conn.go:70 uacp: connecting to opc.tcp://192.168.1.2:4840/ debug: publish: PublishResponse: null debug: publish: eof: pausing publish loop debug: sub: error: EOF debug: sub: pause debug: sub: pause: pause debug: conn.go:94 uacp 5: start HEL/ACK handshake debug: conn.go:429 uacp 5: sent HELF with 59 bytes debug: conn.go:388 uacp 5: recv ACKF with 28 bytes debug: conn.go:271 uacp 5: recv &uacp.Acknowledge{Version:0x0, ReceiveBufSize:0x2000, SendBufSize:0x2000, MaxMessageSize:0x200000, MaxChunkCount:0x100} debug: secure_channel.go:576 sc.open debug: secure_channel_instance.go:89 got sequence number 1 debug: secure_channel.go:1050 uasc 5/1: send *ua.OpenSecureChannelRequest with 132 bytes debug: conn.go:388 uacp 5: recv OPNF with 136 bytes debug: secure_channel.go:350 uasc 5/1: recv OPNF with 136 bytes debug: secure_channel.go:289 uasc 5/1: recv *ua.OpenSecureChannelResponse debug: secure_channel.go:304 uasc 5/1: sending *ua.OpenSecureChannelResponse to handler debug: secure_channel.go:660 OpenSecureChannelResponse handler debug: secure_channel.go:670 sc.handleOpenSecureChannelResponse debug: secure_channel.go:698 uasc 5: received security token. channelID=1499444091 tokenID=1 createdAt=2025-07-15T15:18:51Z lifetime=1h0m0s debug: client: monitor: secure channel recreated debug: client: monitor: action: restoreSession debug: client: monitor: trying to restore session debug: secure_channel_instance.go:89 got sequence number 2 debug: secure_channel.go:836 uasc 5: security token is refreshed at 2025-07-15T16:03:51Z (45m0s). channelID=1499444091 tokenID=1 debug: secure_channel.go:868 uasc 5: security token expires at 2025-07-15T16:33:51Z. channelID=1499444091 tokenID=1 debug: secure_channel.go:1050 uasc 5/2: send *ua.ActivateSessionRequest with 117 bytes debug: conn.go:388 uacp 5: recv MSGF with 96 bytes debug: secure_channel.go:350 uasc 5/2: recv MSGF with 96 bytes debug: secure_channel.go:289 uasc 5/2: recv *ua.ActivateSessionResponse debug: secure_channel.go:304 uasc 5/2: sending *ua.ActivateSessionResponse to handler debug: secure_channel_instance.go:89 got sequence number 3 debug: secure_channel.go:1050 uasc 5/3: send *ua.CloseSessionRequest with 63 bytes debug: conn.go:388 uacp 5: recv MSGF with 52 bytes debug: secure_channel.go:350 uasc 5/3: recv MSGF with 52 bytes debug: secure_channel.go:289 uasc 5/3: recv *ua.CloseSessionResponse debug: secure_channel.go:304 uasc 5/3: sending *ua.CloseSessionResponse to handler debug: client: monitor: session restored debug: client: monitor: trying to update namespaces debug: secure_channel_instance.go:89 got sequence number 4 debug: secure_channel.go:1050 uasc 5/4: send *ua.ReadRequest with 99 bytes debug: conn.go:388 uacp 5: recv MSGF with 52 bytes debug: secure_channel.go:350 uasc 5/4: recv MSGF with 52 bytes debug: secure_channel.go:287 uasc 5/4: err: The session id is not valid. StatusBadSessionIDInvalid (0x80250000) debug: secure_channel.go:304 uasc 5/4: sending *ua.ServiceFault to handler debug: client: monitor: updating namespaces failed: The session id is not valid. StatusBadSessionIDInvalid (0x80250000) debug: client: monitor: action: createSecureChannel debug: conn.go:221 uacp 5: close debug: secure_channel.go:329 uasc 5: readChunk EOF debug: secure_channel.go:1180 uasc 5: Close() debug: client: monitor: trying to recreate secure channel debug: conn.go:70 uacp: connecting to opc.tcp://192.168.1.2:4840/ debug: conn.go:94 uacp 6: start HEL/ACK handshake debug: conn.go:429 uacp 6: sent HELF with 59 bytes debug: conn.go:388 uacp 6: recv ACKF with 28 bytes debug: conn.go:271 uacp 6: recv &uacp.Acknowledge{Version:0x0, ReceiveBufSize:0x2000, SendBufSize:0x2000, MaxMessageSize:0x200000, MaxChunkCount:0x100} debug: secure_channel.go:576 sc.open debug: secure_channel_instance.go:89 got sequence number 1 debug: secure_channel.go:1050 uasc 6/1: send *ua.OpenSecureChannelRequest with 132 bytes debug: conn.go:388 uacp 6: recv OPNF with 136 bytes debug: secure_channel.go:350 uasc 6/1: recv OPNF with 136 bytes