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

Debian Server Telegraf Docker Container fails to connect to OPCUA while Ubuntu Machine connects #15325

Closed
default-student opened this issue May 8, 2024 · 9 comments
Labels
bug unexpected problem or unintended behavior

Comments

@default-student
Copy link

Relevant telegraf.conf

# Retrieve data from OPCUA devices
[[inputs.opcua]]
  ## Metric name
  name = "Kuehlungsanlage"
  #
  ## OPC UA Endpoint URL
  endpoint = "opc.tcp://192.168.82.220:4840"

  security_policy = "None"
  security_mode = "None"
  auth_method = "Anonymous"
  ## Node IDs to subscribe to
    ### 600_DB_Frostschutz_Schrittkette

    # ns=3;s="600_DB_Frostschutz_Schrittkette"."boFrostschutzErforderlich"
    [[inputs.opcua.nodes]]
        name = "Frostschutz Erforderlich"
        namespace = "3"
        identifier_type = "s"
        identifier = "\"600_DB_Frostschutz_Schrittkette\".\"boFrostschutzErforderlich\""
        data_type = "bool"

Logs from Telegraf

2024-05-08T13:23:54Z D! [agent] Starting service inputs

2024-05-08T13:24:00Z D! [inputs.opcua] Connecting OPC UA Client to server

2024-05-08T13:24:00Z D! [inputs.opcua] Configuring OPC UA connection options

2024-05-08T13:24:00Z D! [inputs.opcua] security policy from configuration http://opcfoundation.org/UA/SecurityPolicy#None

2024-05-08T13:24:00Z D! [inputs.opcua] User cares about both the policy (http://opcfoundation.org/UA/SecurityPolicy#None) and security mode (MessageSecurityModeNone)

2024-05-08T13:24:00Z D! [inputs.opcua] Server has 5 endpoints

2024-05-08T13:24:00Z D! [inputs.opcua] Evaluating endpoint opc.tcp://192.168.82.220:4840, policy http://opcfoundation.org/UA/SecurityPolicy#None, mode MessageSecurityModeNone, level 0

2024-05-08T13:24:00Z D! [inputs.opcua] Security policy and mode found. Using server endpoint opc.tcp://192.168.82.220:4840 for security. Policy http://opcfoundation.org/UA/SecurityPolicy#None

2024-05-08T13:24:00Z D! [inputs.opcua] Evaluating endpoint opc.tcp://192.168.82.220:4840, policy http://opcfoundation.org/UA/SecurityPolicy#Basic256, mode MessageSecurityModeSign, level 60

2024-05-08T13:24:00Z D! [inputs.opcua] Evaluating endpoint opc.tcp://192.168.82.220:4840, policy http://opcfoundation.org/UA/SecurityPolicy#Basic256, mode MessageSecurityModeSignAndEncrypt, level 110

2024-05-08T13:24:00Z D! [inputs.opcua] Evaluating endpoint opc.tcp://192.168.82.220:4840, policy http://opcfoundation.org/UA/SecurityPolicy#Basic256Sha256, mode MessageSecurityModeSign, level 65

2024-05-08T13:24:00Z D! [inputs.opcua] Evaluating endpoint opc.tcp://192.168.82.220:4840, policy http://opcfoundation.org/UA/SecurityPolicy#Basic256Sha256, mode MessageSecurityModeSignAndEncrypt, level 115

2024-05-08T13:24:00Z E! [inputs.opcua] Error in plugin: connect failed: error in Client Connection: EOF

System info

Telegraf 1.30.2, Debian GNU/Linux 12 (bookworm), Docker version 25.0.3, build 4debf41

Docker

No response

Steps to reproduce

1.Start the docker-compose on the Debian Server
2.Check the logs
3.See that it cant connect to the opcua server

Expected behavior

On my local Pc (Ubuntu 22.04.4 LTS, Docker version 25.0.3, build 4debf41, Telegraf 1.30.2) this config works as expected.

telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:25:44Z W! DeprecationWarning: Option "data_type" of plugin "inputs.opcua" deprecated since version 1.17.0 and will be removed in 2.0.0: option is ignored
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:25:44Z I! Starting Telegraf 1.27.4
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:25:44Z I! Available plugins: 237 inputs, 9 aggregators, 28 processors, 23 parsers, 59 outputs, 4 secret-stores
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:25:44Z I! Loaded inputs: opcua
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:25:44Z I! Loaded aggregators: 
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:25:44Z I! Loaded processors: 
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:25:44Z I! Loaded secretstores: 
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:25:44Z I! Loaded outputs: influxdb_v2
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:25:44Z I! Tags enabled: 
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:25:44Z W! Deprecated inputs: 0 and 34 options
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:25:44Z I! [agent] Config: Interval:10s, Quiet:false, Hostname:"", Flush Interval:10s
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:25:44Z D! [agent] Initializing plugins
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:25:44Z D! [inputs.opcua] Initialising OpcUAInputClient
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:25:44Z D! [inputs.opcua] Initialising OpcUAClient
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:25:44Z D! [inputs.opcua] Initialising node to metric mapping
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:25:44Z D! [agent] Connecting outputs
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:25:44Z D! [agent] Attempting connection to [outputs.influxdb_v2]
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:25:44Z D! [agent] Successfully connected to outputs.influxdb_v2
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:25:44Z D! [agent] Starting service inputs
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:25:55Z E! [inputs.opcua] Error in plugin: connect failed: context deadline exceeded
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:26:00Z D! [inputs.opcua] Connecting OPC UA Client to server
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:26:01Z D! [inputs.opcua] Configuring OPC UA connection options
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:26:01Z W! [inputs.opcua] Failed to load certificate: open /etc/telegraf/key.pem: permission denied
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:26:01Z D! [inputs.opcua] security policy from configuration http://opcfoundation.org/UA/SecurityPolicy#None
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:26:01Z D! [inputs.opcua] User cares about both the policy (http://opcfoundation.org/UA/SecurityPolicy#None) and security mode (MessageSecurityModeNone)
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:26:01Z D! [inputs.opcua] Server has 5 endpoints
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:26:01Z D! [inputs.opcua] Evaluating endpoint opc.tcp://192.168.82.220:4840, policy http://opcfoundation.org/UA/SecurityPolicy#None, mode MessageSecurityModeNone, level 0
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:26:01Z D! [inputs.opcua] Security policy and mode found. Using server endpoint opc.tcp://192.168.82.220:4840 for security. Policy http://opcfoundation.org/UA/SecurityPolicy#None
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:26:01Z D! [inputs.opcua] Evaluating endpoint opc.tcp://192.168.82.220:4840, policy http://opcfoundation.org/UA/SecurityPolicy#Basic256, mode MessageSecurityModeSign, level 60
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:26:01Z D! [inputs.opcua] Evaluating endpoint opc.tcp://192.168.82.220:4840, policy http://opcfoundation.org/UA/SecurityPolicy#Basic256, mode MessageSecurityModeSignAndEncrypt, level 110
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:26:01Z D! [inputs.opcua] Evaluating endpoint opc.tcp://192.168.82.220:4840, policy http://opcfoundation.org/UA/SecurityPolicy#Basic256Sha256, mode MessageSecurityModeSign, level 65
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:26:01Z D! [inputs.opcua] Evaluating endpoint opc.tcp://192.168.82.220:4840, policy http://opcfoundation.org/UA/SecurityPolicy#Basic256Sha256, mode MessageSecurityModeSignAndEncrypt, level 115
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:26:01Z D! [inputs.opcua] Connected to OPC UA Server
telegraf-kuehlungsanlage-opcua_1  | 2024-05-08T13:26:04Z D! [outputs.influxdb_v2] Wrote batch of 34 metrics in 28.484215ms

It fails once but succeeds then.
This should also happen on the Debian Server.

Actual behavior

The Telegraf Docker Container on the Debian server fails to connect.

Additional info

The OPCUA server can be pinged from the Debian server.

ping 192.168.82.220
PING 192.168.82.220 (192.168.82.220) 56(84) bytes of data.
64 bytes from 192.168.82.220: icmp_seq=1 ttl=255 time=0.418 ms
64 bytes from 192.168.82.220: icmp_seq=2 ttl=255 time=0.406 ms

nc -zv 192.168.82.220 4840
192.168.82.220: inverse host lookup failed: Unknown host
(UNKNOWN) [192.168.82.220] 4840 (?) open

@default-student default-student added the bug unexpected problem or unintended behavior label May 8, 2024
@powersj
Copy link
Contributor

powersj commented May 8, 2024

Debian Server Telegraf Docker Container fails to connect to OPCUA while Ubuntu Machine connects

If you are able to successfully connect from one server, but not another then this points at something in networking getting in the way not Telegraf. Telegraf is produed as a static binary, so the binaries and libraries themselves are exactly the same.

My suggestion is to set client_trace = true in your [[inputs.opcua]] config to get even more verbose information about your connection. However, this does not point to an issue in Telegraf.

If you get additional data, such that you resolve the issue, you should post this here so others can learn from it or we can determine if the docs need updating.

@powersj powersj added the waiting for response waiting for response from contributor label May 8, 2024
@default-student
Copy link
Author

I tried to add the tracing, but it does not work.
2024-05-08T13:51:49Z I! Starting Telegraf 1.21.4+ds1-0ubuntu2
2024-05-08T13:51:49Z E! [telegraf] Error running agent: Error loading config file ./telegraf/conf/telegraf-kuehlungsanlage-opcua.conf: plugin inputs.opcua: line 36: configuration specified the fields ["client_trace"], but they weren't used

The working ping and accessible port makes me believe that the networking is alright, but maybe it isnt...

@telegraf-tiger telegraf-tiger bot removed the waiting for response waiting for response from contributor label May 8, 2024
@powersj
Copy link
Contributor

powersj commented May 8, 2024

Starting Telegraf 1.21.4+ds1-0ubuntu2

This is not the same version you said you were using in your report Telegraf 1.30.2 ;)

That option is only available in newer versions.

@powersj powersj added the waiting for response waiting for response from contributor label May 8, 2024
@default-student
Copy link
Author

Thank you for the quick answer, i will investigate further.

@telegraf-tiger telegraf-tiger bot removed the waiting for response waiting for response from contributor label May 8, 2024
@powersj powersj added the waiting for response waiting for response from contributor label May 8, 2024
@default-student
Copy link
Author

Sorry for the wait, was finally able to get to it.

the client trace shows the origin of the EOF i guess

2024-05-14T07:14:25Z D! [agent] Initializing plugins
2024-05-14T07:14:25Z D! [inputs.opcua] Initialising OpcUAInputClient
2024-05-14T07:14:25Z D! [inputs.opcua] Initialising OpcUAClient
2024-05-14T07:14:25Z D! [inputs.opcua] Initialising node to metric mapping
2024-05-14T07:14:25Z D! [agent] Starting service inputs
2024-05-14T07:14:25Z D! [inputs.opcua] Connecting OPC UA Client to server
2024-05-14T07:14:25Z D! [inputs.opcua] uacp: connecting to opc.tcp://192.168.82.220:4840
2024-05-14T07:14:25Z D! [inputs.opcua] uacp 1: start HEL/ACK handshake
2024-05-14T07:14:25Z D! [inputs.opcua] uacp 1: sent HELF with 61 bytes
2024-05-14T07:14:25Z D! [inputs.opcua] uacp 1: recv ACKF with 28 bytes
2024-05-14T07:14:25Z D! [inputs.opcua] uacp 1: recv &uacp.Acknowledge{Version:0x0, ReceiveBufSize:0x2000, SendBufSize:0x2000, MaxMessageSize:0x200000, MaxChunkCount:0x100}
2024-05-14T07:14:25Z D! [inputs.opcua] uasc 1/1: send *ua.OpenSecureChannelRequest with 132 bytes
2024-05-14T07:14:25Z D! [inputs.opcua] uacp 1: recv OPNF with 136 bytes
2024-05-14T07:14:25Z D! [inputs.opcua] uasc 1/1: recv OPNF with 136 bytes
2024-05-14T07:14:25Z D! [inputs.opcua] uasc 1/1: recv *ua.OpenSecureChannelResponse
2024-05-14T07:14:25Z D! [inputs.opcua] uasc 1/1: sending *ua.OpenSecureChannelResponse to handler
2024-05-14T07:14:25Z D! [inputs.opcua] uasc 1: received security token. channelID=1812551821 tokenID=1 createdAt=2024-05-14T08:57:27Z lifetime=1h0m0s
2024-05-14T07:14:25Z D! [inputs.opcua] uasc 1/2: send *ua.GetEndpointsRequest with 98 bytes
2024-05-14T07:14:25Z D! [inputs.opcua] uasc 1: security token is refreshed at 2024-05-14T07:59:25Z (45m0s). channelID=1812551821 tokenID=1
2024-05-14T07:14:25Z D! [inputs.opcua] uasc 1: security token expires at 2024-05-14T10:12:27Z. channelID=1812551821 tokenID=1
2024-05-14T07:14:25Z D! [inputs.opcua] uacp 1: recv MSGF with 6969 bytes
2024-05-14T07:14:25Z D! [inputs.opcua] uasc 1/2: recv MSGF with 6969 bytes
2024-05-14T07:14:25Z D! [inputs.opcua] uasc 1/2: recv *ua.GetEndpointsResponse
2024-05-14T07:14:25Z D! [inputs.opcua] uasc 1/2: sending *ua.GetEndpointsResponse to handler
2024-05-14T07:14:25Z D! [inputs.opcua] uasc 1: Close()
2024-05-14T07:14:25Z D! [inputs.opcua] uasc 1/3: send *ua.CloseSecureChannelRequest with 57 bytes
2024-05-14T07:14:25Z D! [inputs.opcua] uacp 1: close
2024-05-14T07:14:25Z D! [inputs.opcua] uasc 1: readChunk EOF
2024-05-14T07:14:25Z D! [inputs.opcua] Configuring OPC UA connection options
2024-05-14T07:14:25Z D! [inputs.opcua] Loading cert/key from /etc/telegraf/cert.pem//etc/telegraf/key.pem
2024-05-14T07:14:25Z D! [inputs.opcua] security policy from configuration http://opcfoundation.org/UA/SecurityPolicy#None
2024-05-14T07:14:25Z D! [inputs.opcua] User cares about both the policy (http://opcfoundation.org/UA/SecurityPolicy#None) and security mode (MessageSecurityModeNone)
2024-05-14T07:14:25Z D! [inputs.opcua] Server has 5 endpoints
2024-05-14T07:14:25Z D! [inputs.opcua] Evaluating endpoint opc.tcp://192.168.82.220:4840, policy http://opcfoundation.org/UA/SecurityPolicy#None, mode MessageSecurityModeNone, level 0
2024-05-14T07:14:25Z D! [inputs.opcua] Security policy and mode found. Using server endpoint opc.tcp://192.168.82.220:4840 for security. Policy http://opcfoundation.org/UA/SecurityPolicy#None
2024-05-14T07:14:25Z D! [inputs.opcua] Evaluating endpoint opc.tcp://192.168.82.220:4840, policy http://opcfoundation.org/UA/SecurityPolicy#Basic256, mode MessageSecurityModeSign, level 60
2024-05-14T07:14:25Z D! [inputs.opcua] Evaluating endpoint opc.tcp://192.168.82.220:4840, policy http://opcfoundation.org/UA/SecurityPolicy#Basic256, mode MessageSecurityModeSignAndEncrypt, level 110
2024-05-14T07:14:25Z D! [inputs.opcua] Evaluating endpoint opc.tcp://192.168.82.220:4840, policy http://opcfoundation.org/UA/SecurityPolicy#Basic256Sha256, mode MessageSecurityModeSign, level 65
2024-05-14T07:14:25Z D! [inputs.opcua] Evaluating endpoint opc.tcp://192.168.82.220:4840, policy http://opcfoundation.org/UA/SecurityPolicy#Basic256Sha256, mode MessageSecurityModeSignAndEncrypt, level 115
2024-05-14T07:14:25Z D! [inputs.opcua] uacp: connecting to opc.tcp://192.168.82.220:4840
2024-05-14T07:14:25Z D! [inputs.opcua] uacp 2: start HEL/ACK handshake
2024-05-14T07:14:25Z D! [inputs.opcua] uacp 2: sent HELF with 61 bytes
2024-05-14T07:14:25Z D! [inputs.opcua] uacp 2: recv ACKF with 28 bytes
2024-05-14T07:14:25Z D! [inputs.opcua] uacp 2: recv &uacp.Acknowledge{Version:0x0, ReceiveBufSize:0x2000, SendBufSize:0x2000, MaxMessageSize:0x200000, MaxChunkCount:0x100}
2024-05-14T07:14:25Z D! [inputs.opcua] uasc 2/1: send *ua.OpenSecureChannelRequest with 1332 bytes
2024-05-14T07:14:25Z D! [inputs.opcua] uacp 2: recv ERRF with 16 bytes
2024-05-14T07:14:25Z D! [inputs.opcua] uasc 2: readChunk EOF
2024-05-14T07:14:25Z D! [inputs.opcua] uasc 2: failed to open a new secure channel
2024-05-14T07:14:25Z D! [inputs.opcua] uacp 2: close
2024-05-14T07:14:25Z E! [inputs.opcua] Error in plugin: connect failed: error in Client Connection: EOF
2024-05-14T07:14:25Z D! [agent] Stopping service inputs
2024-05-14T07:14:25Z D! [agent] Input channel closed
2024-05-14T07:14:25Z D! [agent] Stopped Successfully
2024-05-14T07:14:25Z E! [telegraf] Error running agent: input plugins recorded 1 errors
root@2d0259f63fa0:/app# ping 192.168.82.220     
PING 192.168.82.220 (192.168.82.220) 56(84) bytes of data.
64 bytes from 192.168.82.220: icmp_seq=1 ttl=254 time=0.509 ms
64 bytes from 192.168.82.220: icmp_seq=2 ttl=254 time=0.377 ms

meanwhile locally it works even with 1.30.2

2024-05-14T07:19:57Z I! Starting Telegraf 1.30.2 brought to you by InfluxData the makers of InfluxDB
2024-05-14T07:19:57Z I! Available plugins: 233 inputs, 9 aggregators, 31 processors, 24 parsers, 60 outputs, 6 secret-stores
2024-05-14T07:19:57Z I! Loaded inputs: opcua
2024-05-14T07:19:57Z I! Loaded aggregators: 
2024-05-14T07:19:57Z I! Loaded processors: 
2024-05-14T07:19:57Z I! Loaded secretstores: 
2024-05-14T07:19:57Z W! Outputs are not used in testing mode!
2024-05-14T07:19:57Z I! Tags enabled: 
2024-05-14T07:19:57Z W! Deprecated inputs: 0 and 34 options
2024-05-14T07:19:57Z D! [agent] Initializing plugins
2024-05-14T07:19:57Z D! [inputs.opcua] Initialising OpcUAInputClient
2024-05-14T07:19:57Z D! [inputs.opcua] Initialising OpcUAClient
2024-05-14T07:19:57Z D! [inputs.opcua] Initialising node to metric mapping
2024-05-14T07:19:57Z D! [agent] Starting service inputs
2024-05-14T07:19:57Z D! [inputs.opcua] Connecting OPC UA Client to server
2024-05-14T07:19:57Z D! [inputs.opcua] uacp: connecting to opc.tcp://192.168.82.220:4840
2024-05-14T07:19:57Z D! [inputs.opcua] uacp 1: start HEL/ACK handshake
2024-05-14T07:19:57Z D! [inputs.opcua] uacp 1: sent HELF with 61 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uacp 1: recv ACKF with 28 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uacp 1: recv &uacp.Acknowledge{Version:0x0, ReceiveBufSize:0x2000, SendBufSize:0x2000, MaxMessageSize:0x200000, MaxChunkCount:0x100}
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 1/1: send *ua.OpenSecureChannelRequest with 132 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uacp 1: recv OPNF with 136 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 1/1: recv OPNF with 136 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 1/1: recv *ua.OpenSecureChannelResponse
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 1/1: sending *ua.OpenSecureChannelResponse to handler
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 1: received security token. channelID=1812551826 tokenID=1 createdAt=2024-05-14T09:02:59Z lifetime=1h0m0s
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 1: security token is refreshed at 2024-05-14T08:04:57Z (45m0s). channelID=1812551826 tokenID=1
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 1: security token expires at 2024-05-14T10:17:59Z. channelID=1812551826 tokenID=1
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 1/2: send *ua.GetEndpointsRequest with 98 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uacp 1: recv MSGF with 6969 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 1/2: recv MSGF with 6969 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 1/2: recv *ua.GetEndpointsResponse
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 1/2: sending *ua.GetEndpointsResponse to handler
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 1: Close()
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 1/3: send *ua.CloseSecureChannelRequest with 57 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uacp 1: close
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 1: readChunk EOF
2024-05-14T07:19:57Z D! [inputs.opcua] Configuring OPC UA connection options
2024-05-14T07:19:57Z D! [inputs.opcua] Loading cert/key from /etc/telegraf/cert.pem//etc/telegraf/key.pem
2024-05-14T07:19:57Z W! [inputs.opcua] Failed to load certificate: open /etc/telegraf/key.pem: permission denied
2024-05-14T07:19:57Z D! [inputs.opcua] security policy from configuration http://opcfoundation.org/UA/SecurityPolicy#None
2024-05-14T07:19:57Z D! [inputs.opcua] User cares about both the policy (http://opcfoundation.org/UA/SecurityPolicy#None) and security mode (MessageSecurityModeNone)
2024-05-14T07:19:57Z D! [inputs.opcua] Server has 5 endpoints
2024-05-14T07:19:57Z D! [inputs.opcua] Evaluating endpoint opc.tcp://192.168.82.220:4840, policy http://opcfoundation.org/UA/SecurityPolicy#None, mode MessageSecurityModeNone, level 0
2024-05-14T07:19:57Z D! [inputs.opcua] Security policy and mode found. Using server endpoint opc.tcp://192.168.82.220:4840 for security. Policy http://opcfoundation.org/UA/SecurityPolicy#None
2024-05-14T07:19:57Z D! [inputs.opcua] Evaluating endpoint opc.tcp://192.168.82.220:4840, policy http://opcfoundation.org/UA/SecurityPolicy#Basic256, mode MessageSecurityModeSign, level 60
2024-05-14T07:19:57Z D! [inputs.opcua] Evaluating endpoint opc.tcp://192.168.82.220:4840, policy http://opcfoundation.org/UA/SecurityPolicy#Basic256, mode MessageSecurityModeSignAndEncrypt, level 110
2024-05-14T07:19:57Z D! [inputs.opcua] Evaluating endpoint opc.tcp://192.168.82.220:4840, policy http://opcfoundation.org/UA/SecurityPolicy#Basic256Sha256, mode MessageSecurityModeSign, level 65
2024-05-14T07:19:57Z D! [inputs.opcua] Evaluating endpoint opc.tcp://192.168.82.220:4840, policy http://opcfoundation.org/UA/SecurityPolicy#Basic256Sha256, mode MessageSecurityModeSignAndEncrypt, level 115
2024-05-14T07:19:57Z D! [inputs.opcua] uacp: connecting to opc.tcp://192.168.82.220:4840
2024-05-14T07:19:57Z D! [inputs.opcua] uacp 2: start HEL/ACK handshake
2024-05-14T07:19:57Z D! [inputs.opcua] uacp 2: sent HELF with 61 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uacp 2: recv ACKF with 28 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uacp 2: recv &uacp.Acknowledge{Version:0x0, ReceiveBufSize:0x2000, SendBufSize:0x2000, MaxMessageSize:0x200000, MaxChunkCount:0x100}
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 2/1: send *ua.OpenSecureChannelRequest with 132 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uacp 2: recv OPNF with 136 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 2/1: recv OPNF with 136 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 2/1: recv *ua.OpenSecureChannelResponse
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 2/1: sending *ua.OpenSecureChannelResponse to handler
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 2: received security token. channelID=1812551827 tokenID=1 createdAt=2024-05-14T09:02:59Z lifetime=1h0m0s
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 2: security token is refreshed at 2024-05-14T08:04:57Z (45m0s). channelID=1812551827 tokenID=1
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 2/2: send *ua.CreateSessionRequest with 249 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 2: security token expires at 2024-05-14T10:17:59Z. channelID=1812551827 tokenID=1
2024-05-14T07:19:57Z D! [inputs.opcua] uacp 2: recv MSGF with 8052 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 2/2: recv MSGF with 8052 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 2/2: recv *ua.CreateSessionResponse
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 2/2: sending *ua.CreateSessionResponse to handler
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 2/3: send *ua.ActivateSessionRequest with 117 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uacp 2: recv MSGF with 96 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 2/3: recv MSGF with 96 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 2/3: recv *ua.ActivateSessionResponse
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 2/3: sending *ua.ActivateSessionResponse to handler
debug: client: monitor: start
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 2/4: send *ua.ReadRequest with 99 bytes
debug: sub: pause
2024-05-14T07:19:57Z D! [inputs.opcua] uacp 2: recv MSGF with 232 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 2/4: recv MSGF with 232 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 2/4: recv *ua.ReadResponse
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 2/4: sending *ua.ReadResponse to handler
2024-05-14T07:19:57Z D! [inputs.opcua] Connected to OPC UA Server
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 2/5: send *ua.RegisterNodesRequest with 1796 bytes
2024-05-14T07:19:58Z D! [inputs.opcua] uacp 2: recv MSGF with 294 bytes
2024-05-14T07:19:58Z D! [inputs.opcua] uasc 2/5: recv MSGF with 294 bytes
2024-05-14T07:19:58Z D! [inputs.opcua] uasc 2/5: recv *ua.RegisterNodesResponse
2024-05-14T07:19:58Z D! [inputs.opcua] uasc 2/5: sending *ua.RegisterNodesResponse to handler
2024-05-14T07:19:58Z D! [inputs.opcua] uasc 2/6: send *ua.ReadRequest with 792 bytes
2024-05-14T07:19:58Z D! [inputs.opcua] uacp 2: recv MSGF with 770 bytes
2024-05-14T07:19:58Z D! [inputs.opcua] uasc 2/6: recv MSGF with 770 bytes
2024-05-14T07:19:58Z D! [inputs.opcua] uasc 2/6: recv *ua.ReadResponse
2024-05-14T07:19:58Z D! [inputs.opcua] uasc 2/6: sending *ua.ReadResponse to handler
2024-05-14T07:19:58Z D! [inputs.opcua] uasc 2/7: send *ua.ReadRequest with 792 bytes
2024-05-14T07:19:58Z D! [inputs.opcua] uacp 2: recv MSGF with 770 bytes
2024-05-14T07:19:58Z D! [inputs.opcua] uasc 2/7: recv MSGF with 770 bytes
2024-05-14T07:19:58Z D! [inputs.opcua] uasc 2/7: recv *ua.ReadResponse
2024-05-14T07:19:58Z D! [inputs.opcua] uasc 2/7: sending *ua.ReadResponse to handler
2024-05-14T07:19:58Z D! [agent] Stopping service inputs
2024-05-14T07:19:58Z D! [agent] Input channel closed
2024-05-14T07:19:58Z D! [agent] Stopped Successfully
> Kuehlungsanlage,id=ns\=3;s\="600_DB_Frostschutz_Schrittkette"."boFrostschutzErforderlich" Frostschutz\ Erforderlich=false,Quality="The operation succeeded. StatusGood (0x0)" 1715671198000000000

the important lines to me are:
in docker this happens and telegraf cannot connect:

2024-05-14T07:14:25Z D! [inputs.opcua] uasc 2/1: send *ua.OpenSecureChannelRequest with 1332 bytes
2024-05-14T07:14:25Z D! [inputs.opcua] uacp 2: recv ERRF with 16 bytes
2024-05-14T07:14:25Z D! [inputs.opcua] uasc 2: readChunk EOF

meanwhile locally it works:

2024-05-14T07:19:57Z D! [inputs.opcua] uasc 2/1: send *ua.OpenSecureChannelRequest with 132 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uacp 2: recv OPNF with 136 bytes
2024-05-14T07:19:57Z D! [inputs.opcua] uasc 2/1: recv OPNF with 136 byte

@telegraf-tiger telegraf-tiger bot removed the waiting for response waiting for response from contributor label May 14, 2024
@default-student
Copy link
Author

with 132 bytes

locally vs in docker

with 1332 bytes

is that a hint?

@default-student
Copy link
Author

2024-05-14T07:57:26Z D! [inputs.opcua_listener] Evaluating endpoint opc.tcp://192.168.82.220:4840, policy http://opcfoundation.org/UA/SecurityPolicy#Basic256Sha256, mode MessageSecurityModeSignAndEncrypt, level 115
2024-05-14T07:57:26Z D! [inputs.opcua_listener] uacp: connecting to opc.tcp://192.168.82.220:4840
2024-05-14T07:57:26Z D! [inputs.opcua_listener] uacp 2: start HEL/ACK handshake
2024-05-14T07:57:26Z D! [inputs.opcua_listener] uacp 2: sent HELF with 61 bytes
2024-05-14T07:57:27Z D! [inputs.opcua_listener] uacp 2: recv ACKF with 28 bytes
2024-05-14T07:57:27Z D! [inputs.opcua_listener] uacp 2: recv &uacp.Acknowledge{Version:0x0, ReceiveBufSize:0x2000, SendBufSize:0x2000, MaxMessageSize:0x200000, MaxChunkCount:0x100}
2024-05-14T07:57:27Z D! [inputs.opcua_listener] uasc 2/1: send *ua.OpenSecureChannelRequest with 1332 bytes
2024-05-14T07:57:27Z D! [inputs.opcua_listener] uacp 2: recv ERRF with 16 bytes
2024-05-14T07:57:27Z D! [inputs.opcua_listener] uasc 2: readChunk EOF
2024-05-14T07:57:27Z D! [inputs.opcua_listener] uasc 2: failed to open a new secure channel
2024-05-14T07:57:27Z D! [inputs.opcua_listener] uacp 2: close
2024-05-14T07:57:27Z E! [telegraf] Error running agent: starting input inputs.opcua_listener: error in Client Connection: EOF

Also reproducible with the opcua_listener plugin

@default-student
Copy link
Author

I got it to work!
removing /etc/telegraf/cert.pem /etc/telegraf/key.pem enables it to connect. This might be my misunderstanding!
It is however still very unstable. Every once in a while

2024-05-14T08:25:00Z D! [inputs.opcua] uasc 3/11: send *ua.CloseSecureChannelRequest with 57 bytes
telegraf-kuehlungsanlage-opcua_1  | 2024-05-14T08:25:00Z D! [inputs.opcua] uacp 3: close
telegraf-kuehlungsanlage-opcua_1  | 2024-05-14T08:25:00Z D! [inputs.opcua] uasc 3: readChunk EOF
telegraf-kuehlungsanlage-opcua_1  | 2024-05-14T08:25:00Z E! [inputs.opcua] Error in plugin: RegisterNodes Read failed: The session id is not valid. StatusBadSessionIDInvali

causes the telegraf instance to reconnect.
it seems input.opcua_listener doesnt have this issue... but it seems its minimal reporting interval sadly cant be configured, probably cause it wasnt made for that.

I while i am happy gopcua exists, it doesnt seem stable to me.
If you want to close it at that, feel free to do so.

@powersj
Copy link
Contributor

powersj commented May 14, 2024

removing /etc/telegraf/cert.pem /etc/telegraf/key.pem enables it to connect. This might be my misunderstanding!

Thanks for following up and sharing what the root cause was.

it seems input.opcua_listener doesnt have this issue... but it seems its minimal reporting interval sadly cant be configured, probably cause it wasnt made for that.

The listener only listens so in general it ignores the Telegraf interval. There is the sampling_inerval option to tell the server when to check for new data that might be helpful depending on your situation.

@powersj powersj closed this as not planned Won't fix, can't repro, duplicate, stale May 14, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug unexpected problem or unintended behavior
Projects
None yet
Development

No branches or pull requests

2 participants