Getting "Timeout occurred while processing the request."

[WoodsterDK]

Hi there,

I get "Timeout occurred while processing the request." when trying to read out a value - I'm running:

        session = new UaTcpSessionChannel(appDescription, certificate, userIdentity, remoteEndpoint);
        try
        {
            await session.OpenAsync();
        }

that succeeds without any errors. I then create a readrequest, but that times out on the read:

            var readResponse = await session.ReadAsync(readRequest).ConfigureAwait(false);

Any ideas?

[awcullen]

Every request has a timeout. If the time elapsed during a ReadAsync call exceeds the timeout, then you get an exception with the message "Timeout occurred while processing the request." The default timeout set for the UaTcpSessionChannel is 15 seconds, but you can change it, as:

session = new UaTcpSessionChannel(appDescription, certificate, userIdentity, remoteEndpoint, timeoutHint: 20000);

// the default TimeoutHint is used when the RequestHeader is not set.
 var readRequest = new ReadRequest
 {
     NodesToRead = nodes
 };

Or you can set the timeout of an individual request to 20 seconds, as:

 var readRequest = new ReadRequest
 {
     RequestHeader = new RequestHeader { TimeoutHint = 20000 },
     NodesToRead = nodes
 };

[WoodsterDK]

Yes, without doing anything it times out after 15 seconds, but why is that? The tag is there, and can be read using kepwares opc client tool. If the connect succeeds should the read then also?

[awcullen]

Yes the OpenAsync method sends and receives a number of requests including a ReadRequest for the Namespace table and ServerUris.

Could you share more of your code?

[awcullen]

You can have the channel output tracing to the debugger by following these steps:

Add the packages "Microsoft.Extensions.Logging" and "Microsoft.Extensions.Logging.Debug" to your project. Modify the code that creates the channel:

       var loggerFactory = new LoggerFactory();
       loggerFactory.AddDebug(LogLevel.Trace);
       session = new UaTcpSessionChannel(appDescription, certificate, userIdentity, remoteEndpoint, loggerFactory);

then you should see this in your output window:

Workstation.ServiceModel.Ua.Channels.UaTcpSessionChannel: Trace: Channel opening.
Workstation.ServiceModel.Ua.Channels.UaTcpSessionChannel: Information: Opening session channel with endpoint 'opc.tcp://Andrew-THINK:48010'.
Workstation.ServiceModel.Ua.Channels.UaTcpSessionChannel: Information: SecurityPolicy: 'http://opcfoundation.org/UA/SecurityPolicy#Basic256'.
Workstation.ServiceModel.Ua.Channels.UaTcpSessionChannel: Information: SecurityMode: 'SignAndEncrypt'.
Workstation.ServiceModel.Ua.Channels.UaTcpSessionChannel: Information: UserIdentityToken: 'Workstation.ServiceModel.Ua.AnonymousIdentity'.
Workstation.ServiceModel.Ua.Channels.UaTcpSessionChannel: Trace: Sending OpenSecureChannelRequest Handle: 2
Workstation.ServiceModel.Ua.Channels.UaTcpSessionChannel: Trace: Received OpenSecureChannelResponse Handle: 2 Result: 0x00000000
Workstation.ServiceModel.Ua.Channels.UaTcpSessionChannel: Trace: Sending CreateSessionRequest Handle: 3
Workstation.ServiceModel.Ua.Channels.UaTcpSessionChannel: Trace: Installed new security token 1.
Workstation.ServiceModel.Ua.Channels.UaTcpSessionChannel: Trace: Received CreateSessionResponse Handle: 3 Result: 0x00000000
Workstation.ServiceModel.Ua.Channels.UaTcpSessionChannel: Trace: Sending ActivateSessionRequest Handle: 4
Workstation.ServiceModel.Ua.Channels.UaTcpSessionChannel: Trace: Received ActivateSessionResponse Handle: 4 Result: 0x00000000
Workstation.ServiceModel.Ua.Channels.UaTcpSessionChannel: Trace: Sending ReadRequest Handle: 5
Workstation.ServiceModel.Ua.Channels.UaTcpSessionChannel: Trace: Received ReadResponse Handle: 5 Result: 0x00000000
Workstation.ServiceModel.Ua.Channels.UaTcpSessionChannel: Trace: Channel opened.

[WoodsterDK]

Logger added - I get the following:

Workstation.ServiceModel.Ua.Channels.UaTcpSessionChannel: Trace: Installed new security token 1. Workstation.ServiceModel.Ua.Channels.UaTcpSessionChannel: Trace: Received CreateSessionResponse Handle: 3 Result: 0x00000000 Workstation.ServiceModel.Ua.Channels.UaTcpSessionChannel: Trace: Sending ActivateSessionRequest Handle: 4 Workstation.ServiceModel.Ua.Channels.UaTcpSessionChannel: Trace: Received ActivateSessionResponse Handle: 4 Result: 0x00000000 Workstation.ServiceModel.Ua.Channels.UaTcpSessionChannel: Trace: Sending ReadRequest Handle: 5 Workstation.ServiceModel.Ua.Channels.UaTcpSessionChannel: Trace: Received ReadResponse Handle: 5 Result: 0x00000000 Workstation.ServiceModel.Ua.Channels.UaTcpSessionChannel: Trace: Channel opened. Workstation.ServiceModel.Ua.Channels.UaTcpSessionChannel: Trace: Sending ReadRequest Handle: 6 The thread 0x47f4 has exited with code 0 (0x0). The thread 0x300c has exited with code 0 (0x0). Exception thrown: 'Workstation.ServiceModel.Ua.ServiceResultException' in mscorlib.dll Exception thrown: 'Workstation.ServiceModel.Ua.ServiceResultException' in mscorlib.dll Exception thrown: 'Workstation.ServiceModel.Ua.ServiceResultException' in mscorlib.dll

[awcullen]

I tested this console program with Kepware. Please modify the discoveryUrl for your instance. You will find at first the program will not connect, due to security. On the server computer, open Kepware's Ua Configuration tool and "Trust" the "DataLoggingConsole".

The program will start logging the 'Current Time' node.

// Copyright (c) Converter Systems LLC. All rights reserved.
// Licensed under the MIT license. See LICENSE file in the project root for full license information.

using Microsoft.Extensions.Logging;
using System;
using System.Linq;
using System.Threading.Tasks;
using Workstation.ServiceModel.Ua;
using Workstation.ServiceModel.Ua.Channels;

namespace DataLoggingConsole
{
    internal class Program
    {
        private static void Main(string[] args)
        {
            try
            {
                Task.Run(TestAsync).GetAwaiter().GetResult();
            }
            catch (Exception ex)
            {
                Console.WriteLine(ex.Message);
                Console.WriteLine("Press any key to close the program...");
                Console.ReadKey(true);
            }
        }

        private static async Task TestAsync()
        {
            var discoveryUrl = $"opc.tcp://192.168.1.107:49320";
            var cycleTime = 5000;

            // setup logger
            var loggerFactory = new LoggerFactory();
            loggerFactory.AddDebug(LogLevel.Trace);

            // Describe this app.
            var appDescription = new ApplicationDescription()
            {
                ApplicationName = "DataLoggingConsole",
                ApplicationUri = $"urn:{System.Net.Dns.GetHostName()}:DataLoggingConsole",
                ApplicationType = ApplicationType.Client,
            };

            // Create a certificate store on disk.
            var certificateStore = new DirectoryStore(
                Environment.ExpandEnvironmentVariables(@"%LOCALAPPDATA%\DataLoggingConsole\pki"));

            // Prepare array of nodes to read.
            var readRequest = new ReadRequest
            {
                NodesToRead = new[]
                {
                    new ReadValueId { NodeId = NodeId.Parse("i=2258"), AttributeId = AttributeIds.Value },
                }
            };

            Console.WriteLine("Press any key to end the program...");

            while (!Console.KeyAvailable)
            {
                try
                {
                    await Task.Delay(cycleTime);

                    // Discover endpoints.
                    var getEndpointsRequest = new GetEndpointsRequest
                    {
                        EndpointUrl = discoveryUrl,
                        ProfileUris = new[] { TransportProfileUris.UaTcpTransport }
                    };
                    var getEndpointsResponse = await UaTcpDiscoveryClient.GetEndpointsAsync(getEndpointsRequest).ConfigureAwait(false);
                    if (getEndpointsResponse.Endpoints == null || getEndpointsResponse.Endpoints.Length == 0)
                    {
                        throw new InvalidOperationException($"'{discoveryUrl}' returned no endpoints.");
                    }

                    // Choose the endpoint with highest security level.
                    var remoteEndpoint = getEndpointsResponse.Endpoints.OrderBy(e => e.SecurityLevel).Last();

                    // Choose a User Identity.
                    IUserIdentity userIdentity = null;
                    if (remoteEndpoint.UserIdentityTokens.Any(p => p.TokenType == UserTokenType.Anonymous))
                    {
                        userIdentity = new AnonymousIdentity();
                    }
                    else if (remoteEndpoint.UserIdentityTokens.Any(p => p.TokenType == UserTokenType.UserName))
                    {
                        // a username / password is requested.
                        userIdentity = new UserNameIdentity("root", "secret");
                    }
                    else
                    {
                        Console.WriteLine("Program supports servers requesting Anonymous and UserName identity.");
                    }

                    // Create a session with the server.
                    var session = new UaTcpSessionChannel(appDescription, certificateStore, userIdentity, remoteEndpoint, loggerFactory);
                    try
                    {
                        await session.OpenAsync();

                        while (!Console.KeyAvailable)
                        {
                            // Read the nodes.
                            var readResponse = await session.ReadAsync(readRequest).ConfigureAwait(false);

                            // Write the results.
                            for (int i = 0; i < readRequest.NodesToRead.Length; i++)
                            {
                                Console.WriteLine($"{readRequest.NodesToRead[i].NodeId}; value: {readResponse.Results[i]}");
                            }

                            await Task.Delay(cycleTime);
                        }
                        await session.CloseAsync();
                    }
                    catch
                    {
                        await session.AbortAsync();
                        throw;
                    }
                }
                catch (Exception ex)
                {
                    Console.WriteLine(ex.Message);
                }
            }
        }
    }
}

[WoodsterDK]

Sounds promosing, will test it in a few hours and get back.

[WoodsterDK]

Using your program directly makes it possible to read - so something in my code must be wrong - will look into that today. But as I plan to fetch data using the string representation of the nodes, I tried to modify your code to:

new ReadValueId { NodeId = NodeId.Parse("ns=0;s=CurrentTime"), AttributeId = AttributeIds.Value },

This reports back as unknown node id (same value, just using the string representation)..... do you know what could be the problem?

[WoodsterDK]

Might be my mistake - seems like the CurrentTime only supports numeric nodeid - trying with Simulation Examples.Functions.User1 instead

[WoodsterDK]

Now it seems to be running.... I might suspect that the problem in my application is, that I have splitted out the discovery, and open into different methods. Will look futher into that.

[WoodsterDK]

Seems to be running now - actually don't know what made the difference. Will get back if I get any wiser. Thanks for your super support.

[WoodsterDK]

Hi Again, I think the problem is created by me kicking of a "sampling task", that I await - when doing this a timeout occurs. Is this related to the session being created in a different task/thread? How can this be achieved? Regards

[awcullen]

Could you share your code?

[WoodsterDK]

Heres a sample - I have wrapped the OPC connection in my own class. It is supposed to be used for sampling data defined by a JSON file. lstDataRead3 and lstDataRead4 succeeds, but lstDataRead2 fails.

---

OPC_Client.OPC_Client OPCConnection = new OPC_Client.OPC_Client();

List lstSampleConfig = new List(); List lstException = new List();

OPCConnection.iReadJSON(@"D:\SamplingSetup.json", ref lstSampleConfig, ref lstException);

clsRetVal retVal = await OPCConnection.FindOPCEndpoint("opc.tcp://127.0.0.1:49320", "Test"); retVal = await OPCConnection.CreateSession();

List lstItemToRead = new List();

var varDataStep1 = lstSampleConfig.Where(x => x.iSamplingStep == 1).FirstOrDefault();

foreach(var item in varDataStep1.lstItemsToRead) { lstItemToRead.Add(item.strItemName); }

OPCConnection.vAddData(lstItemToRead);

CancellationTokenSource cancelTokenSourceConnectToPLC = new CancellationTokenSource(); CancellationToken cancelTokenConnectToPLC = cancelTokenSourceConnectToPLC.Token; bool bDoneSampling = false;

clsReadDataRetVal lstDataRead3 = await OPCConnection.AsyncGetData(); clsReadDataRetVal lstDataRead4 = await OPCConnection.AsyncGetData();

Task tskConnectToPLC = System.Threading.Tasks.Task.Factory.StartNew(async () => { do { if (!cancelTokenSourceConnectToPLC.IsCancellationRequested) { clsReadDataRetVal lstDataRead2 = await OPCConnection.AsyncGetData(); } else { bDoneSampling = true; } } while (bDoneSampling == false);

}, cancelTokenConnectToPLC);

[awcullen]

try this:

    OPC_Client.OPC_Client OPCConnection = new OPC_Client.OPC_Client();
    List lstSampleConfig = new List();
    List lstException = new List();
    OPCConnection.iReadJSON(@"D:\SamplingSetup.json", ref lstSampleConfig, ref lstException);
    clsRetVal retVal = await OPCConnection.FindOPCEndpoint("opc.tcp://127.0.0.1:49320", "Test");
    retVal = await OPCConnection.CreateSession();
    List lstItemToRead = new List();
    var varDataStep1 = lstSampleConfig.Where(x => x.iSamplingStep == 1).FirstOrDefault();
    foreach (var item in varDataStep1.lstItemsToRead)
    {
        lstItemToRead.Add(item.strItemName);
    }
    OPCConnection.vAddData(lstItemToRead);
    // added 30 second timeout for demo
    CancellationTokenSource cancelTokenSourceConnectToPLC = new CancellationTokenSource(30000);
    CancellationToken cancelTokenConnectToPLC = cancelTokenSourceConnectToPLC.Token;
    bool bDoneSampling = false;
    clsReadDataRetVal lstDataRead3 = await OPCConnection.AsyncGetData();
    clsReadDataRetVal lstDataRead4 = await OPCConnection.AsyncGetData();
    // changed to Task.Run
    Task tskConnectToPLC = System.Threading.Tasks.Task.Run(async () =>
    {
        do
        {
            // use token here
            if (!cancelTokenConnectToPLC.IsCancellationRequested)
            {
                clsReadDataRetVal lstDataRead2 = await OPCConnection.AsyncGetData();
                // probably wanted a delay here.
                await Task.Delay(500, cancelTokenConnectToPLC);
            }
            else
            {
                bDoneSampling = true;
            }
        } while (bDoneSampling == false);
    }, cancelTokenConnectToPLC);

    // await this task somewhere
    await tskConnectToPLC;

[awcullen]

The important part was changing Task.Factory.StartNew() to Task.Run(). StartNew was returning a Task<Task>, which was completing when the inner task Started. Run returns the unwrapped, inner Task, which completes when bDoneSampling==true.

[WoodsterDK]

Hi, Well spotted - what a silly mistake.... now it works. Thanks for your help.