search

Azure-Samples / iot-edge-opc-plc

Sample OPC UA server with nodes that generate random and increasing data, anomalies and much more ...
MIT License
218 stars 94 forks source link

TCP server channel force channel fault. Bad connection closed 'remote side closed connection in K8S' #363

Closed chunchiehdev closed 2 months ago

chunchiehdev commented 2 months ago

Please provide us with the following information:

This issue is for a: (mark with an x)

- [ ] bug report -> please search issues before submitting
- [ ] feature request
- [x] documentation issue or request
- [ ] regression (a behavior that used to work and stopped in a new release)

Minimal steps to reproduce

deploy opcplc to my AKS for practice and it keep popping up the error message.

apiVersion: apps/v1
kind: Deployment
metadata:
  name: opc-deployment
  namespace: dev
  labels:
    app: opc-simulator
spec:
  replicas: 3
  selector:
    matchLabels:
      app: opc-simulator
  template:
    metadata:
      labels:
        app: opc-simulator
    spec:
      containers:
        - name: opc-simulator-server-container
          image: iotduxte.azurecr.io/opc-plc:opc-plc
          args:
            - "--pn=80"
            - "--sp=true"
            - "--ll=debug"
            - "--nodesfile=../app/customized/node.json"
          ports:
            - containerPort: 80
      imagePullSecrets:
        - name: secret
apiVersion: v1
kind: Service
metadata:
  name: opc-plc-service
  namespace: dev
spec:
  selector:
    app: opc-simulator
  ports:
    - name: opc-ua-port
      protocol: TCP
      port: 80
      targetPort: 80
  type: LoadBalancer

Any log messages given by the failure

[02:44:24 INF] ChannelId 137459: in Closed state.                                                                                                                                             
[02:44:24 INF] ChannelId 137459: closed                                                                                                                                                       
[02:44:24 ERR] TCPSERVERCHANNEL ForceChannelFault Socket=014ECA15, ChannelId=0, TokenId=0, Reason=BadConnectionClosed 'Remote side closed connection'                                         
[02:44:24 INF] ChannelId 138624: in Faulted state.                                                                                                                                            
[02:44:54 ERR] TCPSERVERCHANNEL ForceChannelFault Socket=03E6C92B, ChannelId=0, TokenId=0, Reason=BadConnectionClosed 'Remote side closed connection'                                         
[02:44:54 INF] ChannelId 138677: in Faulted state.                                                                                                                                            
[02:44:55 INF] TCPSERVERCHANNEL Cleanup Socket=009EDA07, ChannelId=0, TokenId=0, Reason=BadConnectionClosed 'Remote side closed connection'                                                   
[02:44:55 INF] ChannelId 137513: in Closed state.                                                                                                                                             
[02:44:55 INF] ChannelId 137513: closed                                                                                                                                                       
[02:44:55 ERR] TCPSERVERCHANNEL ForceChannelFault Socket=02535BE2, ChannelId=0, TokenId=0, Reason=BadConnectionClosed 'Remote side closed connection'                                         
[02:44:55 INF] ChannelId 138678: in Faulted state.                                                                                                                                            
[02:44:55 INF] ChannelId 138694: in Connecting state.                                                                                                                                         
[02:44:55 INF] TCPSERVERCHANNEL SOCKET ATTACHED: 002AC5F6, ChannelId=138694                                                                                                                   
[02:44:55 ERR] TCPSERVERCHANNEL ForceChannelFault Socket=03891A12, ChannelId=0, TokenId=0, Reason=BadConnectionClosed 'Remote side closed connection'                                         
[02:44:55 INF] ChannelId 138679: in Faulted state.                                                                                                                                            
[02:44:55 ERR] TCPSERVERCHANNEL ForceChannelFault Socket=03CDE2FE, ChannelId=0, TokenId=0, Reason=BadConnectionClosed 'Remote side closed connection'                                         
[02:44:55 INF] ChannelId 138680: in Faulted state.                                                                                                                                            
[02:44:55 INF] ChannelId 138695: in Connecting state.                                                                                                                                         
[02:44:55 INF] TCPSERVERCHANNEL SOCKET ATTACHED: 03875B52, ChannelId=138695

Expected/desired behavior

If the container running in my local computer and it doesn't keep popping up error messages, but in AKS it seems like it tries to connect and then fails.

OS and Version?

Local computer: WSL AKS: Debian GNU/Linux

Versions

Local computer: 22.04.3 LTS AKS: 11

Mention any other details that might be useful

Thanks! We'll be in touch soon.

cristipogacean commented 2 months ago

@chunchiehdev, I believe the reason for this is that the trust relationship between your client and server is not properly established. your client try to connect, the server sends it's cert public key which is not trusted therefore the client closes the secure channel without providing a reason. This is normal behavior as per OPC UA Spec. You will need to explicitly establish the mutual trust between the peers (both sides client and server). This is done by adding the server's public key certificate in the client's trusted certificates store and the client's public key certificate in the server's trusted certificates store.

chunchiehdev commented 2 months ago

@cristipogacean ,When I initially deployed to opc-plc AKS, I did not use any client-side tools to attempt a connection. However, it continuously keeps creating ChannelIds, and the ChannelIds keep increasing. Could this be related to network restrictions?

[08:47:49 INF] Node values will change every 10000 ms                                                                                                                                         
[08:47:49 INF] Node values sampling rate is 0 ms                                                                                                                                              
[08:47:49 INF] ChannelId 1: in Connecting state.                                                                                                                                              
[08:47:49 INF] TCPSERVERCHANNEL SOCKET ATTACHED: 023404EE, ChannelId=1                                                                                                                        
[08:47:49 INF] Server - CreateEventManager.                                                                                                                                                   
[08:47:49 INF] Server - CreateAggregateManager.                                                                                                                                               
[08:47:49 INF] Server - CreateSessionManager.                                                                                                                                                 
[08:47:49 INF] Server - CreateSubscriptionManager.                                                                                                                                            
[08:47:49 INF] Server - Session Monitor Thread Started.                                                                                                                                       
[08:47:49 INF] Subscription - Publish Thread 0000000D Started.                                                                                                                                
[08:47:49 INF] Server - Enter Running state.                                                                                                                                                  
[08:47:49 INF] Server - Started.                                                                                                                                                              
[08:47:49 INF] OPC UA Server started                                                                                                                                                          
[08:47:49 INF] PLC simulation started, press Ctrl+C to exit ...                                                                                                                               
[08:47:49 INF] ChannelId 2: in Connecting state.                                                                                                                                              
[08:47:49 INF] TCPSERVERCHANNEL SOCKET ATTACHED: 01AC495C, ChannelId=2                                                                                                                        
[08:47:50 INF] ChannelId 3: in Connecting state.                                                                                                                                              
[08:47:50 INF] TCPSERVERCHANNEL SOCKET ATTACHED: 0342F10B, ChannelId=3                                                                                                                        
[08:47:50 INF] ChannelId 4: in Connecting state.                                                                                                                                              
[08:47:50 INF] TCPSERVERCHANNEL SOCKET ATTACHED: 025F14A9, ChannelId=4                                                                                                                        
[08:47:50 INF] ChannelId 5: in Connecting state.                                                                                                                                              
[08:47:50 INF] TCPSERVERCHANNEL SOCKET ATTACHED: 01FA0ABC, ChannelId=5                                                                                                                        
[08:47:51 INF] ChannelId 6: in Connecting state.                                                                                                                                              
[08:47:51 INF] TCPSERVERCHANNEL SOCKET ATTACHED: 00DC0E29, ChannelId=6                                                                                                                        
[08:47:51 INF] ChannelId 7: in Connecting state.                                                                                                                                              
[08:47:51 INF] TCPSERVERCHANNEL SOCKET ATTACHED: 02B6A1CA, ChannelId=7                                                                                                                        
[08:47:51 INF] ChannelId 8: in Connecting state.                                                                                                                                              
[08:47:51 INF] TCPSERVERCHANNEL SOCKET ATTACHED: 021A7086, ChannelId=8                                                                                                                        
[08:47:51 INF] ChannelId 9: in Connecting state.                         
[08:47:51 INF] TCPSERVERCHANNEL SOCKET ATTACHED: 021A7086, ChannelId=8                                                                                                                        
[08:47:51 INF] ChannelId 9: in Connecting state.                                                                                                                                              
[08:47:51 INF] TCPSERVERCHANNEL SOCKET ATTACHED: 02A5C7B8, ChannelId=9                                                                                                                        
[08:47:52 INF] ChannelId 10: in Connecting state.                                                                                                                                             
[08:47:52 INF] TCPSERVERCHANNEL SOCKET ATTACHED: 021EB607, ChannelId=10                                                                                                                       
[08:47:54 INF] ChannelId 11: in Connecting state.                                                                                                                                             
[08:47:54 INF] TCPSERVERCHANNEL SOCKET ATTACHED: 03D8C971, ChannelId=11                                                                                                                       
[08:48:32 INF] ChannelId 81: in Connecting state.                                                                                                                                             
[08:48:32 INF] TCPSERVERCHANNEL SOCKET ATTACHED: 00D7EBF3, ChannelId=81                                                                                                                       
[08:48:32 ERR] TCPSERVERCHANNEL ForceChannelFault Socket=028BAC6A, ChannelId=0, TokenId=0, Reason=BadConnectionClosed 'Remote side closed connection'                                         
[08:48:32 INF] ChannelId 75: in Faulted state.                                                                                                                                                
[08:48:32 INF] ChannelId 82: in Connecting state.                                                                                                                                             
[08:48:32 INF] TCPSERVERCHANNEL SOCKET ATTACHED: 028D4EAB, ChannelId=82
cristipogacean commented 2 months ago

I see. just noticed you're using port 80. This is not exactly indicated for OPC UA Applications. The default port of opc plc is 50000. I'm assuming that some entity in your environment is constantly attempting to connect on port 80. I suggest you use a different port, not that common.

chunchiehdev commented 2 months ago

Thank you. But I already set up the port number --pn=80 and also export it to 80. When I use docker to run the opcplc. Then it will be normal on my computer. Like this.

 docker run --rm -it -p 80:80 -p 8080:8080 --name opcplc mcr.microsoft.com/iotedge/opc-plc:latest --pn=80 --autoaccept --sn=5 --sr=10 --st=uint --fn=5 --fr=1 --ft=uint --gn=5 --ll=trace --ph=opcplc --cdn=opcplc

It won't automatically create the ChannelId; it only logs the ChannelId when I use a connection tool to connect to it. I believe this is normal behavior.

<6>2024-06-14T09:24:06.000Z - Node values will change every 10000 ms
<6>2024-06-14T09:24:06.187Z - Server - CreateEventManager.
<6>2024-06-14T09:24:06.195Z - Server - CreateAggregateManager.
<6>2024-06-14T09:24:06.197Z - Server - CreateSessionManager.
<6>2024-06-14T09:24:06.199Z - Server - CreateSubscriptionManager.
<6>2024-06-14T09:24:06.200Z - Server - Session Monitor Thread Started.
<6>2024-06-14T09:24:06.203Z - Subscription - ConditionRefresh Thread 0000000D Started.
<6>2024-06-14T09:24:06.203Z - Subscription - Publish Thread 0000000C Started.
<6>2024-06-14T09:24:06.204Z - Server - Enter Running state.
<6>2024-06-14T09:24:06.204Z - Server - Started.
<6>2024-06-14T09:24:06.205Z - OPC UA Server started
<6>2024-06-14T09:24:06.208Z - PLC simulation started, press Ctrl+C to exit ...
cristipogacean commented 2 months ago

right, in Kubernetes context though, there might be k8s infrastructure entities that try to check the pod's health and use port 80 by default. This is done automatically without user's control, therefore the behavior of your server might be different than in a regular docker context.

chunchiehdev commented 2 months ago

Thank you so much!