Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Unable to transfer a subscription from one client to another #4618

Open
4 of 7 tasks
smitha-cgi opened this issue Aug 30, 2021 · 2 comments
Open
4 of 7 tasks

Unable to transfer a subscription from one client to another #4618

smitha-cgi opened this issue Aug 30, 2021 · 2 comments

Comments

@smitha-cgi
Copy link

Description

Unable to transfer a subscription from one client to another

Background Information / Reproduction Steps

Create a client connection to server, set up a subscription, create another connection, transfer the subscription over. Server returns success but never publishes any messages after the transfer is completed. This seems to be because the library doesn't pick up on the fact that the subscription has been transferred, and as such the subscriptions list for the second client is empty, so when UA_Client_subscriptions_backgroundPublish is called, it returns straight away.

void UA_Client_Subscriptions_backgroundPublish(UA_Client *client) {
    if(client->sessionState < UA_SESSIONSTATE_ACTIVATED)
        return;

    /* The session must have at least one subscription */
    if(!LIST_FIRST(&client->subscriptions))
        return;

Sample code that reproduces the issue is below. This was copied from the 'Client_subscription_transfer' method from the test suite and modified to remove the asserts and put in a couple more iterates in order to check that the original subscription was working. Note that the Client_subscription_transfer test function as it is currently written doesn't actually test anything to do with the transfer - it is simply checking to see if multiple connections can be made to the server, so that test will always pass.

Sample code

static void dataChangeHandler(UA_Client *client, UA_UInt32 subId, void *subContext,
    UA_UInt32 monId, void *monContext, UA_DataValue *value)
{
    printf("Received data change\n");
}

int main(void) 
{
    UA_Client *client = UA_Client_new();
    UA_ClientConfig_setDefault(UA_Client_getConfig(client));

    UA_StatusCode retval = UA_Client_connect(client, "opc.tcp://localhost:4840");

    UA_CreateSubscriptionRequest request = UA_CreateSubscriptionRequest_default();
    request.requestedLifetimeCount = 5;
    UA_CreateSubscriptionResponse response = UA_Client_Subscriptions_create(client, request,
                                                              NULL, NULL, NULL);

    /* monitor the server state */
    UA_MonitoredItemCreateRequest monRequest =
        UA_MonitoredItemCreateRequest_default(UA_NODEID_NUMERIC(0, UA_NS0ID_SERVER_SERVERSTATUS_CURRENTTIME));

    UA_MonitoredItemCreateResult monResponse =
        UA_Client_MonitoredItems_createDataChange(client, response.subscriptionId,
                                                  UA_TIMESTAMPSTORETURN_BOTH,
                                                  monRequest, NULL, dataChangeHandler, NULL);

    //Iterate to see that messages are being received from server
    for (int ctr = 0; ctr < 5; ctr++)
    {
        UA_Client_run_iterate(client, 1000);
    }

    /* Create a second client */
    UA_Client *client2 = UA_Client_new();
    UA_ClientConfig_setDefault(UA_Client_getConfig(client2));

    retval = UA_Client_connect(client2, "opc.tcp://localhost:4840");

    /* Move the subscription to the second client */
    UA_TransferSubscriptionsRequest trequest;
    UA_TransferSubscriptionsRequest_init(&trequest);
    trequest.subscriptionIds = &response.subscriptionId;
    trequest.subscriptionIdsSize = 1;

    UA_TransferSubscriptionsResponse tresponse;
    __UA_Client_Service(client2,
                        &trequest, &UA_TYPES[UA_TYPES_TRANSFERSUBSCRIPTIONSREQUEST],
                        &tresponse,  &UA_TYPES[UA_TYPES_TRANSFERSUBSCRIPTIONSRESPONSE]);

    UA_TransferSubscriptionsResponse_clear(&tresponse);

    //Iterate the clients some more to see what happens 
    //At this point we should see printf messages coming through indicating that data is still being received via client2 connection
    for (int ctr = 0; ctr < 5; ctr++)
    {
        UA_Client_run_iterate(client, 1000);
        UA_Client_run_iterate(client2, 1000);
    }

    /* Delete */
    UA_Client_disconnect(client);
    UA_Client_delete(client);
    UA_Client_disconnect(client2);
    UA_Client_delete(client2);
}

Used CMake options:

UA_ENABLE_DA=1 UA_ENABLE_DISCOVERY=1 UA_ENABLE_ENCRYPTION=1 UA_ENABLE_ENCRYPTION_OPENSSL=1 
UA_ENABLE_METHODCALLS=1 UA_ENABLE_NODEMANAGEMENT=1 UA_ENABLE_PARSING=1 
UA_ENABLE_SUBSCRIPTIONS=1 UA_LOGLEVEL=100 UA_MULTITHREADING=0

Checklist

Please provide the following information:

  • open62541 Version (release number or git tag): 1.2
  • Other OPC UA SDKs used (client or server): Prosys OPC UA Simulation Server
  • Operating system: Windows 7
  • Logs (with UA_LOGLEVEL set as low as necessary) attached
  • Wireshark network dump attached
  • Self-contained code example attached
  • Critical issue
@jpfr
Copy link
Member

jpfr commented Aug 30, 2021

What is the returned status code?
Does a reason get logged when you decrease the log level?

@smitha-cgi
Copy link
Author

Status code returned by the server is 0.

image

If I search through the source code for 'TransferSubscriptionRequest' and 'TransferSubscriptionsResponse' they only exist in the build\src_generated and src\server folders. Nothing on the client side does anything at all with the request or the response - I assume it should be keeping track of which subscription ids were sent in the request, and if the response comes back ok, adding those the list of subscriptions for the client so that publish requests will be sent out. Although there doesn't seem to be enough information in the transfer request or response to create a new UA_Subscription object from scratch, so I'm not sure how that is supposed to work.

Here is the full output with UA_LOGLEVEL set to 0 showing nothing happening after the transfer response.

[2021-08-31 09:14:09.529 (UTC+1000)] warn/userland      AcceptAll Certificate Verification. Any remote certificate will be accepted.
[2021-08-31 09:14:09.540 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:09.561 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:09.563 (UTC+1000)] debug/network      Sent HEL message
[2021-08-31 09:14:09.564 (UTC+1000)] debug/client       Client Status: ChannelState: HELSent, SessionState: Closed, ConnectStatus: Good
[2021-08-31 09:14:09.566 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:09.567 (UTC+1000)] debug/network      Received ACK message
[2021-08-31 09:14:09.572 (UTC+1000)] debug/client       Client Status: ChannelState: AckReceived, SessionState: Closed, ConnectStatus: Good
[2021-08-31 09:14:09.573 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:09.573 (UTC+1000)] debug/channel      Connection 144 | SecureChannel 0 | Generating new local nonce
[2021-08-31 09:14:09.576 (UTC+1000)] debug/channel      Connection 144 | SecureChannel 0 | Requesting to open a SecureChannel
[2021-08-31 09:14:09.577 (UTC+1000)] debug/channel      Requesting to open a SecureChannel
[2021-08-31 09:14:09.580 (UTC+1000)] debug/channel      OPN message sent
[2021-08-31 09:14:09.588 (UTC+1000)] debug/client       Client Status: ChannelState: OPNSent, SessionState: Closed, ConnectStatus: Good
[2021-08-31 09:14:09.590 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:09.592 (UTC+1000)] trace/channel      Connection 144 | SecureChannel 29 | Verifying chunk signature
[2021-08-31 09:14:09.593 (UTC+1000)] trace/channel      Connection 144 | SecureChannel 29 | Generating new local keys
[2021-08-31 09:14:09.594 (UTC+1000)] info/channel       Connection 144 | SecureChannel 29 | SecureChannel opened with SecurityPolicy http://opcfoundation.org/UA/SecurityPolicy#None and a revised lifetime of 600.00s
[2021-08-31 09:14:09.602 (UTC+1000)] info/client        Client Status: ChannelState: Open, SessionState: Closed, ConnectStatus: Good
[2021-08-31 09:14:09.604 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:09.605 (UTC+1000)] debug/channel      Connection 144 | SecureChannel 29 | Sending request with RequestId 2 of type GetEndpointsRequest
[2021-08-31 09:14:09.608 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:09.611 (UTC+1000)] trace/channel      Connection 144 | SecureChannel 29 | Generating new remote keys
[2021-08-31 09:14:09.616 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:09.617 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:09.621 (UTC+1000)] info/client        Rejecting endpoint 0: security policy not available
[2021-08-31 09:14:09.624 (UTC+1000)] info/client        Rejecting endpoint 1: security policy not available
[2021-08-31 09:14:09.625 (UTC+1000)] info/client        Rejecting UserTokenPolicy 0 in endpoint 2: security policy 'http://opcfoundation.org/UA/SecurityPolicy#Basic128Rsa15' not available
[2021-08-31 09:14:09.626 (UTC+1000)] info/client        Rejecting UserTokenPolicy 1 in endpoint 2: security policy 'http://opcfoundation.org/UA/SecurityPolicy#Basic256' not available
[2021-08-31 09:14:09.627 (UTC+1000)] info/client        Rejecting UserTokenPolicy 2 in endpoint 2: security policy 'http://opcfoundation.org/UA/SecurityPolicy#Basic128Rsa15' not available
[2021-08-31 09:14:09.632 (UTC+1000)] info/client        Rejecting UserTokenPolicy 3 in endpoint 2: security policy 'http://opcfoundation.org/UA/SecurityPolicy#Basic256' not available
[2021-08-31 09:14:09.642 (UTC+1000)] info/client        Selected Endpoint opc.tcp://localhost:4840 with SecurityMode None and SecurityPolicy http://opcfoundation.org/UA/SecurityPolicy#None
[2021-08-31 09:14:09.655 (UTC+1000)] info/client        Selected UserTokenPolicy anonymous with UserTokenType Anonymous and SecurityPolicy http://opcfoundation.org/UA/SecurityPolicy#None
[2021-08-31 09:14:09.675 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:09.681 (UTC+1000)] debug/channel      Connection 144 | SecureChannel 29 | Sending request with RequestId 3 of type CreateSessionRequest
[2021-08-31 09:14:09.691 (UTC+1000)] debug/client       Client Status: ChannelState: Open, SessionState: CreateRequested, ConnectStatus: Good
[2021-08-31 09:14:09.714 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:09.717 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:09.721 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:09.729 (UTC+1000)] info/client        Client Status: ChannelState: Open, SessionState: Created, ConnectStatus: Good
[2021-08-31 09:14:09.732 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:09.738 (UTC+1000)] debug/channel      Connection 144 | SecureChannel 29 | Sending request with RequestId 4 of type ActivateSessionRequest
[2021-08-31 09:14:09.743 (UTC+1000)] debug/client       Client Status: ChannelState: Open, SessionState: ActivateRequested, ConnectStatus: Good
[2021-08-31 09:14:09.766 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:09.773 (UTC+1000)] info/client        Client Status: ChannelState: Open, SessionState: Activated, ConnectStatus: Good
[2021-08-31 09:14:09.777 (UTC+1000)] debug/channel      Connection 144 | SecureChannel 29 | Sending request with RequestId 5 of type CreateSubscriptionRequest
[2021-08-31 09:14:09.791 (UTC+1000)] debug/client       Decode a message of type CreateSubscriptionResponse
[2021-08-31 09:14:09.797 (UTC+1000)] debug/channel      Connection 144 | SecureChannel 29 | Sending request with RequestId 6 of type CreateMonitoredItemsRequest
[2021-08-31 09:14:09.807 (UTC+1000)] debug/client       Decode a message of type CreateMonitoredItemsResponse
[2021-08-31 09:14:09.821 (UTC+1000)] debug/client       Subscription 17 | Added a MonitoredItem with handle 1
[2021-08-31 09:14:09.827 (UTC+1000)] debug/channel      Connection 144 | SecureChannel 29 | Sending request with RequestId 7 of type PublishRequest
[2021-08-31 09:14:09.830 (UTC+1000)] debug/channel      Connection 144 | SecureChannel 29 | Sending request with RequestId 8 of type PublishRequest
[2021-08-31 09:14:09.833 (UTC+1000)] debug/channel      Connection 144 | SecureChannel 29 | Sending request with RequestId 9 of type PublishRequest
[2021-08-31 09:14:09.840 (UTC+1000)] debug/channel      Connection 144 | SecureChannel 29 | Sending request with RequestId 10 of type PublishRequest
[2021-08-31 09:14:09.844 (UTC+1000)] debug/channel      Connection 144 | SecureChannel 29 | Sending request with RequestId 11 of type PublishRequest
[2021-08-31 09:14:09.857 (UTC+1000)] debug/channel      Connection 144 | SecureChannel 29 | Sending request with RequestId 12 of type PublishRequest
[2021-08-31 09:14:09.861 (UTC+1000)] debug/channel      Connection 144 | SecureChannel 29 | Sending request with RequestId 13 of type PublishRequest
[2021-08-31 09:14:09.875 (UTC+1000)] debug/channel      Connection 144 | SecureChannel 29 | Sending request with RequestId 14 of type PublishRequest
[2021-08-31 09:14:09.881 (UTC+1000)] debug/channel      Connection 144 | SecureChannel 29 | Sending request with RequestId 15 of type PublishRequest
[2021-08-31 09:14:09.891 (UTC+1000)] debug/channel      Connection 144 | SecureChannel 29 | Sending request with RequestId 16 of type PublishRequest
Received data change
[2021-08-31 09:14:10.293 (UTC+1000)] debug/channel      Connection 144 | SecureChannel 29 | Sending request with RequestId 17 of type PublishRequest
Received data change
[2021-08-31 09:14:10.793 (UTC+1000)] debug/channel      Connection 144 | SecureChannel 29 | Sending request with RequestId 18 of type PublishRequest
Received data change
[2021-08-31 09:14:11.626 (UTC+1000)] debug/channel      Connection 144 | SecureChannel 29 | Sending request with RequestId 19 of type PublishRequest
Received data change
[2021-08-31 09:14:12.625 (UTC+1000)] debug/channel      Connection 144 | SecureChannel 29 | Sending request with RequestId 20 of type PublishRequest
Received data change
[2021-08-31 09:14:13.626 (UTC+1000)] debug/channel      Connection 144 | SecureChannel 29 | Sending request with RequestId 21 of type PublishRequest
[2021-08-31 09:14:13.635 (UTC+1000)] warn/userland      AcceptAll Certificate Verification. Any remote certificate will be accepted.
[2021-08-31 09:14:13.639 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:13.642 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:13.648 (UTC+1000)] debug/network      Sent HEL message
[2021-08-31 09:14:13.651 (UTC+1000)] debug/client       Client Status: ChannelState: HELSent, SessionState: Closed, ConnectStatus: Good
[2021-08-31 09:14:13.654 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:13.659 (UTC+1000)] debug/network      Received ACK message
[2021-08-31 09:14:13.666 (UTC+1000)] debug/client       Client Status: ChannelState: AckReceived, SessionState: Closed, ConnectStatus: Good
[2021-08-31 09:14:13.670 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:13.683 (UTC+1000)] debug/channel      Connection 156 | SecureChannel 0 | Generating new local nonce
[2021-08-31 09:14:13.689 (UTC+1000)] debug/channel      Connection 156 | SecureChannel 0 | Requesting to open a SecureChannel
[2021-08-31 09:14:13.692 (UTC+1000)] debug/channel      Requesting to open a SecureChannel
[2021-08-31 09:14:13.702 (UTC+1000)] debug/channel      OPN message sent
[2021-08-31 09:14:13.705 (UTC+1000)] debug/client       Client Status: ChannelState: OPNSent, SessionState: Closed, ConnectStatus: Good
[2021-08-31 09:14:13.719 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:13.722 (UTC+1000)] trace/channel      Connection 156 | SecureChannel 30 | Verifying chunk signature
[2021-08-31 09:14:13.725 (UTC+1000)] trace/channel      Connection 156 | SecureChannel 30 | Generating new local keys
[2021-08-31 09:14:13.729 (UTC+1000)] info/channel       Connection 156 | SecureChannel 30 | SecureChannel opened with SecurityPolicy http://opcfoundation.org/UA/SecurityPolicy#None and a revised lifetime of 600.00s
[2021-08-31 09:14:13.736 (UTC+1000)] info/client        Client Status: ChannelState: Open, SessionState: Closed, ConnectStatus: Good
[2021-08-31 09:14:13.744 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:13.748 (UTC+1000)] debug/channel      Connection 156 | SecureChannel 30 | Sending request with RequestId 2 of type GetEndpointsRequest
[2021-08-31 09:14:13.754 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:13.759 (UTC+1000)] trace/channel      Connection 156 | SecureChannel 30 | Generating new remote keys
[2021-08-31 09:14:13.761 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:13.763 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:13.772 (UTC+1000)] info/client        Rejecting endpoint 0: security policy not available
[2021-08-31 09:14:13.773 (UTC+1000)] info/client        Rejecting endpoint 1: security policy not available
[2021-08-31 09:14:13.777 (UTC+1000)] info/client        Rejecting UserTokenPolicy 0 in endpoint 2: security policy 'http://opcfoundation.org/UA/SecurityPolicy#Basic128Rsa15' not available
[2021-08-31 09:14:13.783 (UTC+1000)] info/client        Rejecting UserTokenPolicy 1 in endpoint 2: security policy 'http://opcfoundation.org/UA/SecurityPolicy#Basic256' not available
[2021-08-31 09:14:13.789 (UTC+1000)] info/client        Rejecting UserTokenPolicy 2 in endpoint 2: security policy 'http://opcfoundation.org/UA/SecurityPolicy#Basic128Rsa15' not available
[2021-08-31 09:14:13.793 (UTC+1000)] info/client        Rejecting UserTokenPolicy 3 in endpoint 2: security policy 'http://opcfoundation.org/UA/SecurityPolicy#Basic256' not available
[2021-08-31 09:14:13.805 (UTC+1000)] info/client        Selected Endpoint opc.tcp://localhost:4840 with SecurityMode None and SecurityPolicy http://opcfoundation.org/UA/SecurityPolicy#None
[2021-08-31 09:14:13.810 (UTC+1000)] info/client        Selected UserTokenPolicy anonymous with UserTokenType Anonymous and SecurityPolicy http://opcfoundation.org/UA/SecurityPolicy#None
[2021-08-31 09:14:13.818 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:13.821 (UTC+1000)] debug/channel      Connection 156 | SecureChannel 30 | Sending request with RequestId 3 of type CreateSessionRequest
[2021-08-31 09:14:13.826 (UTC+1000)] debug/client       Client Status: ChannelState: Open, SessionState: CreateRequested, ConnectStatus: Good
[2021-08-31 09:14:13.830 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:13.838 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:13.841 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:13.850 (UTC+1000)] info/client        Client Status: ChannelState: Open, SessionState: Created, ConnectStatus: Good
[2021-08-31 09:14:13.852 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:13.855 (UTC+1000)] debug/channel      Connection 156 | SecureChannel 30 | Sending request with RequestId 4 of type ActivateSessionRequest
[2021-08-31 09:14:13.860 (UTC+1000)] debug/client       Client Status: ChannelState: Open, SessionState: ActivateRequested, ConnectStatus: Good
[2021-08-31 09:14:13.865 (UTC+1000)] trace/client       Client connect iterate
[2021-08-31 09:14:13.868 (UTC+1000)] info/client        Client Status: ChannelState: Open, SessionState: Activated, ConnectStatus: Good
[2021-08-31 09:14:13.870 (UTC+1000)] debug/channel      Connection 156 | SecureChannel 30 | Sending request with RequestId 5 of type TransferSubscriptionsRequest
[2021-08-31 09:14:13.877 (UTC+1000)] debug/client       Decode a message of type TransferSubscriptionsResponse

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@jpfr @smitha-cgi