Skip to content

[Bug]: Umati Sample Server BadIdentityTokenInvalid #2154

@Nguyen-BangVu

Description

@Nguyen-BangVu

What happened?

I am currently working on an application using PLC4X.
The Umati server is running correctly. Everything should be fine

The reason I know this is because everything works fine with UA Expert.
The following log is from the umati server:

[2025-06-24 19:53:59.885 (UTC+0000)] info/channel	TCP 8	| SC 836	| SecureChannel created
[2025-06-24 19:53:59.946 (UTC+0000)] info/channel	TCP 8	| SC 836	| SecureChannel opened with SecurityPolicy http://opcfoundation.org/UA/SecurityPolicy#None and a revised lifetime of 300.00s
[2025-06-24 19:54:00.037 (UTC+0000)] info/channel	TCP 8	| SC 836	| SecureChannel closed
[2025-06-24 19:54:00.037 (UTC+0000)] info/network	TCP 8	| Socket closed
[2025-06-24 19:54:00.037 (UTC+0000)] info/network	TCP 8	| Connection opened from "10.1.10.105" via the server socket 4
[2025-06-24 19:54:00.037 (UTC+0000)] info/channel	TCP 8	| SC 837	| SecureChannel created
[2025-06-24 19:54:00.098 (UTC+0000)] info/channel	TCP 8	| SC 837	| SecureChannel opened with SecurityPolicy http://opcfoundation.org/UA/SecurityPolicy#None and a revised lifetime of 600.00s
[2025-06-24 19:54:00.140 (UTC+0000)] info/session	TCP 8	| SC 837	| Session "ns=1;g=258b0ef3-24d2-274a-b7fb-bf4ba07a5725"	| Session created
[2025-06-24 19:54:00.257 (UTC+0000)] info/session	TCP 8	| SC 837	| Session "ns=1;g=258b0ef3-24d2-274a-b7fb-bf4ba07a5725"	| ActivateSession: Session activated with ClientUserId "admin"
[2025-06-24 19:54:00.381 (UTC+0000)] info/session	TCP 8	| SC 837	| Session "ns=1;g=258b0ef3-24d2-274a-b7fb-bf4ba07a5725"	| Subscription 8 | Subscription created (Publishing interval 100.00ms, max 1000 notifications per publish)
[2025-06-24 19:54:00.413 (UTC+0000)] info/session	TCP 8	| SC 837	| Session "ns=1;g=258b0ef3-24d2-274a-b7fb-bf4ba07a5725"	| Subscription 8 | MonitoredItem 1 | Created the MonitoredItem (Sampling Interval: 0.00ms, Queue Size: 100)
[2025-06-24 20:01:30.108 (UTC+0000)] info/channel	TCP 8	| SC 837	| SecureChannel renewed with a revised lifetime of 600.00s
[2025-06-24 20:09:00.107 (UTC+0000)] info/channel	TCP 8	| SC 837	| SecureChannel renewed with a revised lifetime of 600.00s
[2025-06-24 20:16:30.135 (UTC+0000)] info/channel	TCP 8	| SC 837	| SecureChannel renewed with a revised lifetime of 600.00s
[2025-06-24 20:24:00.133 (UTC+0000)] info/channel	TCP 8	| SC 837	| SecureChannel renewed with a revised lifetime of 600.00s
[2025-06-24 20:31:30.131 (UTC+0000)] info/channel	TCP 8	| SC 837	| SecureChannel renewed with a revised lifetime of 600.00s
[2025-06-24 20:37:25.529 (UTC+0000)] info/network	TCP 9	| Connection opened from "10.1.10.105" via the server socket 4
[2025-06-24 20:37:25.529 (UTC+0000)] info/channel	TCP 9	| SC 838	| SecureChannel created
[2025-06-24 20:37:25.568 (UTC+0000)] info/channel	TCP 9	| SC 838	| SecureChannel opened with SecurityPolicy http://opcfoundation.org/UA/SecurityPolicy#None and a revised lifetime of 600.00s
[2025-06-24 20:37:25.629 (UTC+0000)] info/network	TCP 10	| Connection opened from "10.1.10.105" via the server socket 4
[2025-06-24 20:37:25.629 (UTC+0000)] info/channel	TCP 10	| SC 839	| SecureChannel created
[2025-06-24 20:37:25.668 (UTC+0000)] info/channel	TCP 10	| SC 839	| SecureChannel opened with SecurityPolicy http://opcfoundation.org/UA/SecurityPolicy#None and a revised lifetime of 600.00s
[2025-06-24 20:37:25.686 (UTC+0000)] info/session	TCP 10	| SC 839	| Session "UaSession:OPCUA client for the Apache PLC4X:PLC4J project:M3qa1Cmkmf5xAfoafyUf"	| Session created
[2025-06-24 20:39:00.128 (UTC+0000)] info/channel	TCP 8	| SC 837	| SecureChannel renewed with a revised lifetime of 600.00s
[2025-06-24 20:39:25.690 (UTC+0000)] info/session	TCP 10	| SC 839	| Session "UaSession:OPCUA client for the Apache PLC4X:PLC4J project:M3qa1Cmkmf5xAfoafyUf"	| Session has timed out
[2025-06-24 20:46:12.895 (UTC+0000)] info/network	TCP 11	| Connection opened from "10.1.10.105" via the server socket 4
[2025-06-24 20:46:12.895 (UTC+0000)] info/channel	TCP 11	| SC 840	| SecureChannel created
[2025-06-24 20:46:12.955 (UTC+0000)] info/channel	TCP 11	| SC 840	| SecureChannel opened with SecurityPolicy http://opcfoundation.org/UA/SecurityPolicy#None and a revised lifetime of 600.00s
[2025-06-24 20:46:12.995 (UTC+0000)] info/network	TCP 12	| Connection opened from "10.1.10.105" via the server socket 4
[2025-06-24 20:46:12.995 (UTC+0000)] info/channel	TCP 12	| SC 841	| SecureChannel created
[2025-06-24 20:46:13.056 (UTC+0000)] info/channel	TCP 12	| SC 841	| SecureChannel opened with SecurityPolicy http://opcfoundation.org/UA/SecurityPolicy#None and a revised lifetime of 600.00s
[2025-06-24 20:46:13.074 (UTC+0000)] info/session	TCP 12	| SC 841	| Session "UaSession:OPCUA client for the Apache PLC4X:PLC4J project:ONAqZI2NDjAiZrBvrYAN"	| Session created
[2025-06-24 20:46:30.125 (UTC+0000)] info/channel	TCP 8	| SC 837	| SecureChannel renewed with a revised lifetime of 600.00s
[2025-06-24 20:47:25.686 (UTC+0000)] info/channel	TCP 9	| SC 838	| SecureChannel has timed out
[2025-06-24 20:47:25.686 (UTC+0000)] info/channel	TCP 10	| SC 839	| SecureChannel has timed out
[2025-06-24 20:47:25.687 (UTC+0000)] info/channel	TCP 10	| SC 839	| SecureChannel closed due to timeout
[2025-06-24 20:47:25.687 (UTC+0000)] info/network	TCP 10	| Socket closed
[2025-06-24 20:47:25.687 (UTC+0000)] info/channel	TCP 9	| SC 838	| SecureChannel closed due to timeout
[2025-06-24 20:47:25.687 (UTC+0000)] info/network	TCP 9	| Socket closed
[2025-06-24 20:48:13.686 (UTC+0000)] info/session	TCP 12	| SC 841	| Session "UaSession:OPCUA client for the Apache PLC4X:PLC4J project:ONAqZI2NDjAiZrBvrYAN"	| Session has timed out

all with TCP 8 is from UA Expert and works as expected.
Everthing elsee is an attempt of PLC4X

Both times I used User/Pw identification
I also tried anonymously with the same results

The following log is from PLC4X:

2025-06-24T20:37:25.469525195Z [2025-06-24 20:37:25,468] INFO Starting jobs... (org.apache.plc4x.java.scraper.triggeredscraper.TriggeredScraperImpl)
2025-06-24T20:37:25.469537062Z [2025-06-24 20:37:25,469] INFO Task TriggeredScraperTask{connectionManager=org.apache.plc4x.java.utils.cache.CachedPlcConnectionManager@186fe9d8, jobName='mainjob', connectionAlias='prosys', connectionString='opcua:tcp://10.1.10.106:4840?username=admin&password=admin', requestTimeoutMs=2000, executorService=java.util.concurrent.ThreadPoolExecutor@338e8bc1[Running, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0], resultHandler=org.apache.plc4x.kafka.Plc4xSourceTask$$Lambda$1246/0x0000000101f1e040@43baaafc, triggerHandler=org.apache.plc4x.java.scraper.triggeredscraper.triggerhandler.TriggerHandlerImpl@2c47d5e2} added to scheduling (org.apache.plc4x.java.scraper.triggeredscraper.TriggeredScraperImpl)
2025-06-24T20:37:25.471456373Z [2025-06-24 20:37:25,471] INFO WorkerSourceTask{id=prosys-opcua-connector-0} Source task finished initialization and start (org.apache.kafka.connect.runtime.AbstractWorkerSourceTask)
2025-06-24T20:37:25.480906576Z [2025-06-24 20:37:25,474] INFO Configuring Bootstrap with org.apache.plc4x.java.transport.tcp.DefaultTcpTransportConfiguration@71d543eb (org.apache.plc4x.java.transport.tcp.TcpChannelFactory)
2025-06-24T20:37:25.541029943Z [2025-06-24 20:37:25,540] INFO Received open channel response 1, parsing it (org.apache.plc4x.java.opcua.context.SecureChannel)
2025-06-24T20:37:25.574975646Z [2025-06-24 20:37:25,574] INFO Found OPC UA endpoint opc.tcp://10.1.10.106:4840 (org.apache.plc4x.java.opcua.context.SecureChannel)
2025-06-24T20:37:25.575014403Z [2025-06-24 20:37:25,574] INFO Finished discovery of communication endpoint (org.apache.plc4x.java.opcua.context.SecureChannel)
2025-06-24T20:37:25.575616310Z [2025-06-24 20:37:25,575] INFO Configuring Bootstrap with org.apache.plc4x.java.transport.tcp.DefaultTcpTransportConfiguration@71d543eb (org.apache.plc4x.java.transport.tcp.TcpChannelFactory)
2025-06-24T20:37:25.641474380Z [2025-06-24 20:37:25,641] INFO Received open channel response 1, parsing it (org.apache.plc4x.java.opcua.context.SecureChannel)
2025-06-24T20:37:25.696423196Z [2025-06-24 20:37:25,694] ERROR Failed to establish connection (org.apache.plc4x.java.opcua.protocol.OpcuaProtocolLogic)
2025-06-24T20:37:25.696474282Z java.util.concurrent.CompletionException: org.apache.plc4x.java.api.exceptions.PlcProtocolException: Server returned error BadIdentityTokenInvalid (0x80200000)
2025-06-24T20:37:25.696483086Z 	at java.base/java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:331)
2025-06-24T20:37:25.696490086Z 	at java.base/java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:346)
2025-06-24T20:37:25.696496966Z 	at java.base/java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:632)
2025-06-24T20:37:25.696502464Z 	at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
2025-06-24T20:37:25.696508084Z 	at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2094)

The Error is BadIdentityTokenInvalid
Which I don't understand at all why it pops up
Does plc4x send a different request compared to UA Expert

I also want to add that it works with the prosys server but not with the umati sample server:
If it helps this is the config of PLC4X:

  "name": "prosys-opcua-connector",
  "config": {
    "sources.prosys.connectionString": "opcua:tcp://10.1.10.106:4840?username=admin&password=admin&security-policy=NONE&message-security=NONE",
    "enable.idempotence": "true",
    "sources.prosys.jobReferences": "mainjob",
    "jobs.mainjob.tags": "testValue",
    "acks": "all",
    "jobs.mainjob.interval": "1000",
    "sources.prosys.bufferSize": "1000",
    "sources.prosys.pollReturnInterval": "5000",
    "jobs.mainjob.tags.testValue": "ns=20;i=576843",
    "offset.flush.interval.ms": "10000",
    "offset.storage.file.filename": "/tmp/connect.offsets",
    "value.converter.schemas.enable": "true",
    "name": "prosys-opcua-connector",
    "connector.class": "org.apache.plc4x.kafka.Plc4xSourceConnector",
    "tasks.max": "1",
    "key.converter": "org.apache.kafka.connect.storage.StringConverter",
    "value.converter": "org.apache.kafka.connect.json.JsonConverter",
    "default.topic": "opcua_prosys",
    "sources": "prosys",
    "jobs": "mainjob"
  }
}

Thanks in advance

Version

v13

Programming Languages

  • plc4c
  • plc4go
  • plc4j
  • plc4net
  • plc4py

Protocols

  • AB-Ethernet
  • ADS /AMS
  • BACnet/IP
  • C-Bus
  • CANopen
  • EtherNet/IP
  • Firmata
  • IEC-69870
  • KNXnet/IP
  • Modbus
  • OPC-UA
  • Profinet
  • S7
  • S7-light

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions