UaStatusCodeError(self.value) after a fixed time about opcua-asyncio

[cbergmiller]

If your write:

async with Client(url=url) as client:
    # Do something with client
    await asyncio.sleep(10)

The connection will be closed after 10 seconds. This is intentional.
Either use something like this:

async with Client(url=url) as client:
    while True:
        # Do something with client

Or open the client connection without context manager:

client = asyncua.Client(url=url)
await client.connect()
while True:
    # do something with client
# close connection before you exit the program
await client.disconnect()

I hope this helps.

[cbergmiller]

@1462326016 Subscription.unsubscribe() requires you to pass a handle that was returned by Subscription.subscribe_data_change().
Since Subscription.subscribe_data_change() returns a list of handles you would have to call unsubscribe multiple times.
I suggest you use await subscription.delete() if you want to remove all Subscriptions - it's easier to use.

[cbergmiller]

Hello @jorisvankessel, thanks for reporting this issue.
When the asyncio.sleep(10) finished the Client will disconnect because the code exits the context manager. So my first guess is that a problem occurs while disconnecting from the Server. I tried but could not replicate the issue with a Siemens S7 OPC UA Server. What server did you use to run the example?

[jorisvankessel]

Hi @cbergmiller, thanks for your reply.
At this moment I use an OMRON NX PLC with a OPC UA Server.

[cbergmiller]

Can you record the network traffic with Wireshark while the example ist running and attach the log?

[jorisvankessel]

Here you go:
opc_wireshark.zip

[cbergmiller]

The Server answers with a ServiceFault:

This should be handled when closing the session in opcua/client/ua_client.py:

    async def close_session(self, delete_subscriptions):
        self.logger.info("close_session")
        if self.protocol and self.protocol.state == UASocketProtocol.CLOSED:
            self.logger.warning("close_session was called but connection is closed")
            return
        request = ua.CloseSessionRequest()
        request.DeleteSubscriptions = delete_subscriptions
        data = await self.protocol.send_request(request)
        response = struct_from_binary(ua.CloseSessionResponse, data)
        try:
            response.ResponseHeader.ServiceResult.check()
        except BadSessionClosed:
            # Problem: closing the session with open publish requests leads to BadSessionClosed responses
            #          we can just ignore it therefore.
            #          Alternatively we could make sure that there are no publish requests in flight when
            #          closing the session.
            pass

However it looks like your Server answers the last PublishRequest with a ServiceFault - this case is not handled. We will have to check the OPC UA spec.
For now you could ignore the BadSessionClosed exception as a workaround. As i mentioned before the session will be closed when you exit the Client context manager, this is intentional.

[oroulet]

Yes some servers send residual publish requests after close with service fault. I

[jorisvankessel]

Great, I will implement the workaround for now. Thanks!

[cbergmiller]

@oroulet this could be solved by setting a flag that indicates teardown of the session is in progress before sending the CloseSessionRequest. ServiceFault could then be ignored (when received as a response to a PublishRequest) when the flag is set.

[oroulet]

I kind of remember, it was not so easy to fix. But I have not looked at that code for many years

[jorisvankessel]

Ok, I tried to ignore the BadSessionClosed as you explained above. The session will always be closed in this stadium? I'm not sure what else to do for keep the program running.

Thanks for advising so far.

INFO:asyncua.common.subscription:Publish callback called with result: PublishResult(SubscriptionId:3137412008, AvailableSequenceNumbers:[10], MoreNotifications:False, NotificationMessage:NotificationMessage(SequenceNumber:10, PublishTime:2019-04-22 19:49:27.084079, NotificationData:[DataChangeNotification(MonitoredItems:[MonitoredItemNotification(ClientHandle:201, Value:DataValue(Value:Variant(val:65,type:VariantType.Int16), StatusCode:StatusCode(Good), SourceTimestamp:2019-04-22 19:49:26.771079, ServerTimestamp:2019-04-22 19:49:26.771079))], DiagnosticInfos:[])]), Results:[StatusCode(Good)], DiagnosticInfos:[])
INFO:asyncua.client.ua_client.UaClient:publish
INFO:asyncua.client.client:disconnect
INFO:asyncua.client.ua_client.UaClient:close_session
INFO:asyncua.client.ua_client.UaClient:call_publish_callback
WARNING:asyncua.client.ua_client.UASocketProtocol:ServiceFault from server received while waiting for publish response
ERROR:asyncio:Task exception was never retrieved
future: <Task finished coro=<UaClient._call_publish_callback() done, defined at D:\projects\opcua\lib\site-packages\asyncua\client\ua_client.py:470> exception=BadSessionClosed(2149974016)>
Traceback (most recent call last):
  File "D:\projects\opcua\lib\site-packages\asyncua\client\ua_client.py", line 473, in _call_publish_callback
    self.protocol.check_answer(data, "while waiting for publish response")
  File "D:\projects\opcua\lib\site-packages\asyncua\client\ua_client.py", line 133, in check_answer
    hdr.ServiceResult.check()
  File "D:\projects\opcua\lib\site-packages\asyncua\ua\uatypes.py", line 224, in check
    raise UaStatusCodeError(self.value)
asyncua.ua.uaerrors._auto.BadSessionClosed: The session was closed by the client.(BadSessionClosed)
INFO:asyncua.client.ua_client.UASocketProtocol:close_secure_channel
INFO:asyncua.client.ua_client.UASocketProtocol:Request to close socket received
INFO:asyncua.client.ua_client.UASocketProtocol:Socket has closed connection

[cbergmiller]

@jorisvankessel what are you trying to do? Do you want to keep a client connection open? You can write your code so that is doesn't leave the context manager (e.g. while loop). Or you could use Client.connect() /.disconnect() directly without the context manager.

[jorisvankessel]

@cbergmiller When the BadSessionClosed error appears I wil log this occurrence, but I would like to keep my program running and keep on logging so it won't interference any other process that's running.

[cbergmiller]

I am a bit confused - I am pretty sure the BadSessionClosed Expception is raised because the asyncua client (your program) tries to close the connection. Do you think the OPC UA connection is closed unexpectedly? I am not sure what I would like to keep my program running refers to without more knowledge about your applications architecture.

[jorisvankessel]

Ok not a problem, I will try to explain a littlebit more about the purpose. In my program I subscribe to several tags available in the OPC UA server on the PLC. I store these tagvalues into a database for further processing. This program needs to be running all the time consuming these values. But in my situation the connection will be disconnected after about 10secs because of this BadSessionClosed occurence. In this case I would like to ignore the exception like you suggested and go on with sampling the tagvalues. Somehow ignoring the exception will stil disconnect my OPC UA connection.

[jorisvankessel]

@cbergmiller I was working on your first suggestion, hoping this was the right direction. I will test it, for now thank you for your quick response and thinking along with this.

[libra146]

I also encountered this problem, when I executed await sub.unsubscribe(handle); await sub.delete() after executing await asyncio.sleep(10), it works fine if I don't execute await sub.unsubscribe(handle).The UA server I am using is kepserver.

[cbergmiller]

@1462326016 you also get a BadSessionClosed exception when closing a asyncua.Client connection?
Is this a problem in your application? We need more context (code example, stack trace) to diagnose if this is a related issue.

[libra146]

import asyncio

from asyncua import Client


# logging.basicConfig(level=logging.INFO)

class SubHandler(object):
    def datachange_notification(self, node, val, data):
        # print("New data change event", node, val, data)
        print("New data change event", node, val)

    def event_notification(self, event):
        print("New event", event)


async def run():
    url = "opc.tcp://127.0.0.1:4840"
    async with Client(url=url) as client:
        handler = SubHandler()
        sub = await client.create_subscription(500, handler)
        my = client.get_node('ns=2;s=test.test.alarm.alarm1')
        await sub.subscribe_data_change([my])
        await asyncio.sleep(5)
        sub.unsubscribe(handler)
        del sub


if __name__ == "__main__":
    loop = asyncio.get_event_loop()
    # loop.set_debug(True)
    loop.run_until_complete(run())

My code is here.

New data change event Node(StringNodeId(ns=2;s=test.test.alarm.alarm1)) False
<CoroWrapper Subscription.unsubscribe() running at C:\Python3\lib\site-packages\asyncua\common\subscription.py:272, created at C:\Python3\lib\asyncio\coroutines.py:85> was never yielded from
Coroutine object created at (most recent call last, truncated to 10 last lines):
  File "C:/work/async/client-example.py", line 32, in <module>
    loop.run_until_complete(run())
  File "C:\Python3\lib\asyncio\base_events.py", line 471, in run_until_complete
    self.run_forever()
  File "C:\Python3\lib\asyncio\base_events.py", line 438, in run_forever
    self._run_once()
  File "C:\Python3\lib\asyncio\base_events.py", line 1443, in _run_once
    handle._run()
  File "C:\Python3\lib\asyncio\events.py", line 145, in _run
    self._callback(*self._args)
  File "C:/work/async/client-example.py", line 25, in run
    sub.unsubscribe(handler)
  File "C:\Python3\lib\asyncio\coroutines.py", line 85, in debug_wrapper
    return CoroWrapper(gen, None)
C:/work/async/client-example.py:25: RuntimeWarning: coroutine 'Subscription.unsubscribe' was never awaited
  sub.unsubscribe(handler)
ServiceFault from server received while waiting for publish response
Task exception was never retrieved
future: <Task finished coro=<UaClient._call_publish_callback() done, defined at C:\Python3\lib\site-packages\asyncua\client\ua_client.py:468> exception=BadSessionClosed(2149974016,) created at C:\Python3\lib\site-packages\asyncua\client\ua_client.py:447>
source_traceback: Object created at (most recent call last):
  File "C:/work/async/client-example.py", line 32, in <module>
    loop.run_until_complete(run())
  File "C:\Python3\lib\asyncio\base_events.py", line 471, in run_until_complete
    self.run_forever()
  File "C:\Python3\lib\asyncio\base_events.py", line 438, in run_forever
    self._run_once()
  File "C:\Python3\lib\asyncio\base_events.py", line 1443, in _run_once
    handle._run()
  File "C:\Python3\lib\asyncio\events.py", line 145, in _run
    self._callback(*self._args)
  File "C:\Python3\lib\site-packages\asyncua\client\ua_client.py", line 447, in _sub_data_received
    self.loop.create_task(self._call_publish_callback(data))
Traceback (most recent call last):
  File "C:\Python3\lib\asyncio\coroutines.py", line 126, in send
    return self.gen.send(value)
  File "C:\Python3\lib\site-packages\asyncua\client\ua_client.py", line 471, in _call_publish_callback
    self.protocol.check_answer(data, "while waiting for publish response")
  File "C:\Python3\lib\site-packages\asyncua\client\ua_client.py", line 133, in check_answer
    hdr.ServiceResult.check()
  File "C:\Python3\lib\site-packages\asyncua\ua\uatypes.py", line 224, in check
    raise UaStatusCodeError(self.value)
asyncua.ua.uaerrors._auto.BadSessionClosed: The session was closed by the client.(BadSessionClosed)

进程已结束，退出代码 0

Stack trace is here.

[libra146]

@1462326016 you also get a BadSessionClosed exception when closing a asyncua.Client connection?
Is this a problem in your application? We need more context (code example, stack trace) to diagnose if this is a related issue.

An exception occurs when I run the code for 5 seconds.Is my method correct? I don't know how to upload files. If you need an .opf file, I can send it to you.My version of kepserver is V6.4.321.0

[cbergmiller]

@1462326016 in your example you didn't await sub.unsubscribe(handler). This causes the Exception:
RuntimeWarning: coroutine 'Subscription.unsubscribe' was never awaited sub.unsubscribe(handler)
Can you change that and try again?

[libra146]

@1462326016 in your example you didn't await sub.unsubscribe(handler). This causes the Exception:
RuntimeWarning: coroutine 'Subscription.unsubscribe' was never awaited sub.unsubscribe(handler)
Can you change that and try again?

Thank you very much for replying me so quickly.I modified my program.But he still throws an exception.Stack trace below.I am not sure if it is my problem, it seems to have an error in parsing the binary.But it still happens with asyncua.ua.uaerrors._auto.BadSessionClosed exception.I am very happy to provide more help to solve this problem.

from asyncua import Client


# logging.basicConfig(level=logging.INFO)

class SubHandler(object):
    def datachange_notification(self, node, val, data):
        # print("New data change event", node, val, data)
        print("New data change event", node, val)

    def event_notification(self, event):
        print("New event", event)


async def run():
    url = "opc.tcp://127.0.0.1:4840"
    async with Client(url=url) as client:
        handler = SubHandler()
        sub = await client.create_subscription(500, handler)
        my = client.get_node('ns=2;s=test.test.alarm.alarm1')
        await sub.subscribe_data_change([my])
        await asyncio.sleep(5)
        await sub.unsubscribe(handler)
        await sub.delete()


if __name__ == "__main__":
    loop = asyncio.get_event_loop()
    # loop.set_debug(True)
    loop.run_until_complete(run())

New data change event Node(StringNodeId(ns=2;s=test.test.alarm.alarm1)) False
ServiceFault from server received while waiting for publish response
Task exception was never retrieved
future: <Task finished coro=<UaClient._call_publish_callback() done, defined at C:\Python3\lib\site-packages\asyncua\client\ua_client.py:468> exception=BadSessionClosed(2149974016,) created at C:\Python3\lib\site-packages\asyncua\client\ua_client.py:447>
source_traceback: Object created at (most recent call last):
  File "C:/work/async/client-example.py", line 32, in <module>
    loop.run_until_complete(run())
  File "C:\Python3\lib\asyncio\base_events.py", line 471, in run_until_complete
    self.run_forever()
  File "C:\Python3\lib\asyncio\base_events.py", line 438, in run_forever
    self._run_once()
  File "C:\Python3\lib\asyncio\base_events.py", line 1443, in _run_once
    handle._run()
  File "C:\Python3\lib\asyncio\events.py", line 145, in _run
    self._callback(*self._args)
  File "C:\Python3\lib\site-packages\asyncua\client\ua_client.py", line 447, in _sub_data_received
    self.loop.create_task(self._call_publish_callback(data))
Traceback (most recent call last):
  File "C:\Python3\lib\asyncio\coroutines.py", line 126, in send
    return self.gen.send(value)
  File "C:\Python3\lib\site-packages\asyncua\client\ua_client.py", line 471, in _call_publish_callback
    self.protocol.check_answer(data, "while waiting for publish response")
  File "C:\Python3\lib\site-packages\asyncua\client\ua_client.py", line 133, in check_answer
    hdr.ServiceResult.check()
  File "C:\Python3\lib\site-packages\asyncua\ua\uatypes.py", line 224, in check
    raise UaStatusCodeError(self.value)
asyncua.ua.uaerrors._auto.BadSessionClosed: The session was closed by the client.(BadSessionClosed)
Traceback (most recent call last):
  File "C:/work/async/client-example.py", line 32, in <module>
    loop.run_until_complete(run())
  File "C:\Python3\lib\asyncio\base_events.py", line 484, in run_until_complete
    return future.result()
  File "C:/work/async/client-example.py", line 25, in run
    await sub.unsubscribe(handler)
  File "C:\Python3\lib\asyncio\coroutines.py", line 110, in __next__
    return self.gen.send(None)
  File "C:\Python3\lib\site-packages\asyncua\common\subscription.py", line 280, in unsubscribe
    results = await self.server.delete_monitored_items(params)
  File "C:\Python3\lib\asyncio\coroutines.py", line 110, in __next__
    return self.gen.send(None)
  File "C:\Python3\lib\site-packages\asyncua\client\ua_client.py", line 531, in delete_monitored_items
    data = await self.protocol.send_request(request)
  File "C:\Python3\lib\asyncio\coroutines.py", line 110, in __next__
    return self.gen.send(None)
  File "C:\Python3\lib\site-packages\asyncua\client\ua_client.py", line 120, in send_request
    future = self._send_request(request, callback, timeout, message_type)
  File "C:\Python3\lib\site-packages\asyncua\client\ua_client.py", line 99, in _send_request
    binreq = struct_to_binary(request)
  File "C:\Python3\lib\site-packages\asyncua\ua\ua_binary.py", line 246, in struct_to_binary
    packet.append(to_binary(uatype, val))
  File "C:\Python3\lib\site-packages\asyncua\ua\ua_binary.py", line 269, in to_binary
    return struct_to_binary(val)
  File "C:\Python3\lib\site-packages\asyncua\ua\ua_binary.py", line 241, in struct_to_binary
    packet.append(list_to_binary(uatype[6:], val))
  File "C:\Python3\lib\site-packages\asyncua\ua\ua_binary.py", line 279, in list_to_binary
    return data_type.pack_array(val)
  File "C:\Python3\lib\site-packages\asyncua\ua\ua_binary.py", line 132, in pack_array
    return size_data + struct.pack(self._fmt.format(len(data)), *data)
struct.error: required argument is not an integer

进程已结束，退出代码 1

[libra146]

@1462326016 Subscription.unsubscribe() requires you to pass a handle that was returned by Subscription.subscribe_data_change().
Since Subscription.subscribe_data_change() returns a list of handles you would have to call unsubscribe multiple times.
I suggest you use await subscription.delete() if you want to remove all Subscriptions - it's easier to use.

I used await subscription.delete() and it works fine.
Thank you very much for your help. I have encountered a new problem when I get the node. Can you give me some help? https://github.com/FreeOpcUa/opcua-asyncio/issues/40