UI KeepAlive Timeout

Discussions about product bugs & problems!
Note: This is no replacement for the Official ETM Support!
6 posts • Page 1 of 1
uxout
Posts:82
Joined: Wed Jul 20, 2016 12:07 pm

UI KeepAlive Timeout

Post by uxout »

Hello,

I would like to reduce the timeout of a WinCCOA client UI connected to a server.
Following the logs, it seems there is a default 20s timeout.
Here is the interesting part of the logs (Event manager with parameter "-rcv 1")

WCCILevent0:[WCCILevent(0): 2018.03.05;18:00:43:100 (0.306) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:00:43:100 peerMsgId: 0 msgId: 2477 origMsgId: 2477 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:00:43:795 (0.695) V30F0] R> KEEP_ALIVE Src: (SYS: 1 Ui -num 8 CONN: 1(R)) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Ui -num 8 CONN: 1(R)) originTime: 2018.03.05;18:00:43:795 peerMsgId: 511 msgId: 0 origMsgId: 0 wantAnswer: 0 answerId: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:00:44:199 (0.404) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:00:44:199 peerMsgId: 0 msgId: 2479 origMsgId: 2479 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:00:44:797 (0.598) V30F0] R> KEEP_ALIVE Src: (SYS: 1 Ui -num 8 CONN: 1(R)) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Ui -num 8 CONN: 1(R)) originTime: 2018.03.05;18:00:44:797 peerMsgId: 512 msgId: 0 origMsgId: 0 wantAnswer: 0 answerId: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:00:45:303 (0.506) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:00:45:303 peerMsgId: 0 msgId: 2481 origMsgId: 2481 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:00:46:305 (1.002) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Data -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Data -num 0 CONN: 1) originTime: 2018.03.05;18:00:46:305 peerMsgId: 1507 msgId: 2238 origMsgId: 2238 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:00:46:305 (0.000) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:00:46:305 peerMsgId: 0 msgId: 2483 origMsgId: 2483 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:00:47:316 (1.011) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:00:47:316 peerMsgId: 0 msgId: 2487 origMsgId: 2487 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:00:48:323 (1.007) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:00:48:323 peerMsgId: 0 msgId: 2489 origMsgId: 2489 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:00:49:340 (1.017) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:00:49:340 peerMsgId: 0 msgId: 2491 origMsgId: 2491 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:00:50:356 (1.016) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:00:50:356 peerMsgId: 0 msgId: 2493 origMsgId: 2493 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:00:51:358 (1.002) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Data -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Data -num 0 CONN: 1) originTime: 2018.03.05;18:00:51:358 peerMsgId: 1508 msgId: 2244 origMsgId: 2244 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:00:51:358 (0.000) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:00:51:358 peerMsgId: 0 msgId: 2497 origMsgId: 2497 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:00:52:365 (1.007) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:00:52:365 peerMsgId: 0 msgId: 2499 origMsgId: 2499 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:00:53:370 (1.005) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:00:53:370 peerMsgId: 0 msgId: 2501 origMsgId: 2501 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:00:54:377 (1.007) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:00:54:377 peerMsgId: 0 msgId: 2503 origMsgId: 2503 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:00:55:382 (1.005) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:00:55:382 peerMsgId: 0 msgId: 2505 origMsgId: 2505 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:00:56:386 (1.004) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Data -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Data -num 0 CONN: 1) originTime: 2018.03.05;18:00:56:386 peerMsgId: 1509 msgId: 2250 origMsgId: 2250 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:00:56:386 (0.000) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:00:56:386 peerMsgId: 0 msgId: 2507 origMsgId: 2507 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:00:57:393 (1.007) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:00:57:393 peerMsgId: 0 msgId: 2511 origMsgId: 2511 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:00:58:402 (1.009) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:00:58:402 peerMsgId: 0 msgId: 2513 origMsgId: 2513 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:00:59:413 (1.011) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:00:59:413 peerMsgId: 0 msgId: 2515 origMsgId: 2515 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:01:00:416 (1.003) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:01:00:416 peerMsgId: 0 msgId: 2517 origMsgId: 2517 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:01:01:419 (1.003) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Data -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Data -num 0 CONN: 1) originTime: 2018.03.05;18:01:01:419 peerMsgId: 1510 msgId: 2256 origMsgId: 2256 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:01:01:419 (0.000) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:01:01:419 peerMsgId: 0 msgId: 2519 origMsgId: 2519 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:01:02:427 (1.008) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:01:02:427 peerMsgId: 0 msgId: 2523 origMsgId: 2523 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:01:03:434 (1.007) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:01:03:434 peerMsgId: 0 msgId: 2525 origMsgId: 2525 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent (0), 2018.03.05 18:01:04.708, SYS, INFO, 39, Connection lost, MAN: (SYS: 1 Ui -num 8 CONN: 1(R)), Connection has been closed
WCCILevent0:[WCCILevent(0): 2018.03.05;18:01:04:445 (1.011) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:01:04:445 peerMsgId: 0 msgId: 2527 origMsgId: 2527 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent (0), 2018.03.05 18:01:04.948, SYS, INFO, 39, Connection lost, MAN: (SYS: 1 Ui -num 8 CONN: 1(R)), Connection closed
WCCILevent0:[WCCILevent(0): 2018.03.05;18:01:04:953 (0.508) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:01:04:953 peerMsgId: 0 msgId: 2529 origMsgId: 2529 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:01:04:954 (0.001) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:01:04:954 peerMsgId: 0 msgId: 2534 origMsgId: 2534 wantAnswer: 0 answerId: 0 useServerTime: 0
WCCILevent0:[WCCILevent(0): 2018.03.05;18:01:05:458 (0.504) V30F0] R> DP_MSG_COMPLEX_VC Src: (SYS: 1 Event -num 0 CONN: 1) Dst: (SYS: 1 Event -num 0 CONN: 1) Peer: (SYS: 1 Event -num 0 CONN: 1) originTime: 2018.03.05;18:01:05:458 peerMsgId: 0 msgId: 2537 origMsgId: 2537 wantAnswer: 0 answerId: 0 useServerTime: 0

Any way to reduce that timeout?

Regards

leoknipp
Posts:2928
Joined: Tue Aug 24, 2010 7:28 pm

Re: UI KeepAlive Timeout

Post by leoknipp »

When using the default settings the aliveTimeout for the connection between the server and a UI client running on an other host than the server is 10 seconds.
Where have you seen a 20 seconds timeout?
Why do you want to reduce the timeout?

Best Regards
Leopold Knipp
Senior Support Specialist

uxout
Posts:82
Joined: Wed Jul 20, 2016 12:07 pm

Re: UI KeepAlive Timeout

Post by uxout »

In the log, we can see the last KEEP_ALIVE message from Ui -num 8 came at 2018.03.05;18:00:44:797.
The disconnect for Ui -num 8 came at 2018.03.05 18:01:04.708.
So its a 20s keepalive timeout for me, the config is set with :
[ui]
alivePriorityClass=1
aliveTimeout=-1

I want to detect a client connection lost as soon as possible to prevent an error when reconnecting the UI to the server.
So is there a way to change that timeout setting?

leoknipp
Posts:2928
Joined: Tue Aug 24, 2010 7:28 pm

Re: UI KeepAlive Timeout

Post by leoknipp »

Using an aliveTimeout of 1 seconds is not the normal configuration.
Which error to you want to prevent at the reconnect by using a timeout of 1 second?

If the alive timeout is reached you will get a log message describe in the following FAQ:
https://portal.etm.at/index.php?view=it ... &Itemid=54

Have you seen this log message in the PVSS_II.log?

When starting the UI with the parameter -dbg dispatch you will see the information which alive timeout is used.


+++ Technical information +++

A connection between WinCC OA processes can be closed because of one of the following reasons
1) of a lost network connection detected by the operating system (TCP stack)
2) of missing alive message and reaching the alive timeout

Under normal circumstances and when using the standard configuration for the aliveTimeout the information by the TCP stack is provided earlier than reaching the aliveTimeout. How long it takes until the information is provided by the TCP stack depends on the situation, e.g. which component in the network connection fails.
If the network interface is turned off at one computer this computer will detect very fast the new situation.
When a network component in between the two servers fails it might take a little bit longer.

Therefore not only missing alive messages can be the cause for connection loss.

By analyzing the logfiles you can see which of the described situations (1 and 2) leads to the detection of a lost connection.
The log messages, written to the PVSS_II.log file, look different if the information is received from the TCP stack or when the aliveTimeout was reached.

This log message is written if the information is received from the operating system that the TCP connection was lost.

(1), 2015.11.12 09:41:44.765, SYS, SEVERE, 63, Connection error, Connection reset by peer (10054)


If the alive timeout is reached you will get the following log message

(1), 2015.11.12 09:41:54.696, SYS, SEVERE, 39, Connection lost, Alive timeout expired, closing connection to (). Last message expected at 2015.11.12 09:41:54.675.


Best Regards
Leopold Knipp
Senior Support Specialist

uxout
Posts:82
Joined: Wed Jul 20, 2016 12:07 pm

Re: UI KeepAlive Timeout

Post by uxout »

Oh right then, it must be a lost connection detected by TCP stack. I don't have the alive timeout message.
Is there a way to add alive timeout on UI (client) ?

Thanks for the information

leoknipp
Posts:2928
Joined: Tue Aug 24, 2010 7:28 pm

Re: UI KeepAlive Timeout

Post by leoknipp »

With the config entry aliveTimeout you can define the alive timeout for the connection between the server and client.

Best Regards
Leopold Knipp
Senior Support Specialist

6 posts • Page 1 of 1