Tranquil IT Forum

- Installed WAPT version: 1.5.1.23
- Server OS: Debian 9
- Administration/package creation machine OS: Windows 10

Hello,

For some time now, our WAPT server has stopped reporting the availability of certain machines (actually, most of them). What's incomprehensible is that some of them have no problems at all.

I just upgraded the server from version 1.5.1.21 to 1.5.1.23, and I get the same message when I try to upload the new agent.

By launching the server in debug mode here is what I get:

2018-04-17 15:20:18,691 INFO d573fcb8089e434bb28238dda1e624d3: Received packet MESSAGE data 2["wapt_pong"]
2018-04-17 15:20:18,691 INFO received event "wapt_pong" from d573fcb8089e434bb28238dda1e624d3 [/]
2018-04-17 15:20:18,693 DEBUG Socket.IO pong from wapt client sid d573fcb8089e434bb28238dda1e624d3 (uuid: 7578a06b-0dfb-4631-bd3f-5ad668abff9c)
2018-04-17 15:20:18,695 DEBUG ('UPDATE "hosts" SET "reachable" = %s, "server_uuid" = %s, "listening_protocol" = %s, "listening_address" = %s, "listening_timestamp" = %s WHERE ("hosts".."uuid" = %s)', [u'OK', u'ccbe3738-7c13-11e7-9353-001422b37596', u'websockets', u'd573fcb8089e434bb28238dda1e624d3', u'2018-04-17T15:20:18.693571', u'7578a06b-0dfb-4631-bd3f-5ad668abff9c'])
2018-04-17 15:20:18,705 DEBUG Returning 139838076834184 to pool.
2018-04-17 15:20:18,717 INFO d573fcb8089e434bb28238dda1e624d3: Received packet PING data None
2018-04-17 15:20:18,717 INFO d573fcb8089e434bb28238dda1e624d3: Sending packet PONG data None
2018-04-17 15:20:18,923 DEBUG (1865) accepted ('127.0.0.1', 36760)
2018-04-17 15:20:18,926 INFO f520a971bf9c4b7e962a6f97292ee0a7: Sending packet OPEN data {'pingInterval': 25000, 'pingTimeout': 60000, 'upgrades': ['websocket'], 'sid': 'f520a971bf9c4b7e962a6f97292ee0a7'}
2018-04-17 15:20:18,928 DEBUG ('SELECT "t1".."host_certificate" FROM "hosts" AS t1 WHERE ("t1".."uuid" = %s) LIMIT 1', [u'1E442148-659D-11E4-B810-0F11F5150E00'])
2018-04-17 15:20:18,931 WARNING SocketIO connection refused for uuid 1E442148-659D-11E4-B810-0F11F5150E00, sid f520a971bf9c4b7e962a6f97292ee0a7: Data too old or in the future age: 514s...
2018-04-17 15:20:18,932 DEBUG Returning 139838076834184 to pool.
2018-04-17 15:20:18,934 DEBUG Returning 139838076834184 to pool.
2018-04-17 15:20:18,935 INFO f520a971bf9c4b7e962a6f97292ee0a7: Sending packet MESSAGE data 4
2018-04-17 15:20:18,935 WARNING Application rejected connection
2018-04-17 15:20:18,936 INFO 127.0.0.1 - - [17/Apr/2018 15:20:18] "GET /socket.io/?login=%7B%22uuid%22%3A+%221E442148-659D-11E4-B810-0F11F5150E00%22%2C+%22signature%22%3A+%22iWhnZYSYdNxwP7Xx4FzZUglasWtXEY6NqW4pn%2BCVdMm2H2NM8OG5z1UB2 Fq8AEjIQ55jTWlw%2FBG7W5rGaNT%2Bks5%2BN647M3E0LApRYSXmvW7x85%2BPz%2B%2BJnyRfqcKf4P ujofC8QejzuXYaijA01F2TDzA%2BDiAuIR0SjlOOPl3xlr8a%2Bs8nw%2FcQ%2BJb0A9%2Ft3Assgfse6s qUTbN2PaYxFBKcjrxc3%2FyzdaNUtVenNFVfIbP0LdlgnxRTwgGRPGKLJ5haY3UzMuJaajusB2CAaOHr6 YQ%2BzT6yLlEz%2Bn3jivvoQyw4UQFPmXEo9FXS95y09nqUpmCREsa6cFRkkXjmMLP3oQ%3D%3D%22%2C+ %22signed_attributes%22%3A+%5B%22uuid%22%2C+%22signed_attributes%22%2C+%22signer%22%2C+%22signature_date%22%2C+%22signer_certificate%22%5D%2C+%22signer_certificate [...]

Hello seb-aprolis,

seb-aprolis wrote: ↑Apr 17, 2018 - 3:27 PM ...
For some time now, our WAPT server has stopped reporting the availability of certain machines (actually, most of them). What's incomprehensible is that some of them have no problems at all.

I just upgraded the server from version 1.5.1.21 to 1.5.1.23, and I get the same message when I try to upload the new agent.

When I run the server in debug mode, here's what I get:
B810-0F11F5150E00, sid f520a971bf9c4b7e962a6f97292ee0a7: Data too old or in the future age: 514s
...

Could you please check the time on the server and on the client machines? By default, WAPT accepts a maximum time difference of 5 minutes between the server and the client machine. This tolerance can be increased with the `signature_clockskew` parameter in the `waptserver.ini` file:

https://www.wapt.fr/en/doc-1.5/Configur ... tie-option

Sincerely,

Denis

Thanks for your reply, Denis.

I changed the relevant setting, but it doesn't make much difference. However, I have a question: does SocketIO use CEST or UTC time?

As far as I know, clients are sending CEST time (so, in my case, the Paris time zone). Even though I've set the `signature_clockskew` value to 72,000 (20 minutes), I'm still getting an error message for smaller discrepancies (713 seconds).

Here is an excerpt from the log:
2018-04-18 09:26:05,075 WARNING SocketIO connection refused for uuid 5E56B0BC-659C-11E4-B666-D54C01160E00, sid 9bbed422a96647b09e7012ac3ba53bb3: Data too old or in the future age: 713s...


However, on the PING/PONG requests, I observe that the clients are not sending back anything...

Excerpt from the log:
2018-04-18 09:26:07,944 INFO a4363b4915254ffeb9b8bb2985b6dfc4: Received packet PING data None
2018-04-18 09:26:07,945 INFO a4363b4915254ffeb9b8bb2985b6dfc4: Sending packet PONG data None
2018-04-18 09:26:08,998 INFO 46271366851944f8aa9c2bf7a03549fa: Received packet PING data None
2018-04-18 09:26:08,999 INFO 46271366851944f8aa9c2bf7a03549fa: Sending packet PONG data None
2018-04-18 09:26:09,176 INFO 16d467efc7384eefb02d5be7283d6b8f: Received packet PING data None
2018-04-18 09:26:09,177 INFO 16d467efc7384eefb02d5be7283d6b8f: Sending packet PONG data None
2018-04-18 09:26:09,873 INFO 59494df967ab428fa7c668f3cef3a805: Received packet PING data None
2018-04-18 09:26:09,874 INFO 59494df967ab428fa7c668f3cef3a805: Sending packet PONG data None
2018-04-18 09:26:11,227 INFO 8d1463c48dce43588d62eb62658f9077: Received packet PING data None
2018-04-18 09:26:11,228 INFO 8d1463c48dce43588d62eb62658f9077: Sending packet PONG data None
2018-04-18 09:26:13,243 INFO ccec047c606943efb23b004f2f3a4eed: Received packet PING data None
2018-04-18 09:26:13,243 INFO ccec047c606943efb23b004f2f3a4eed: Sending packet PONG data None
2018-04-18 09:26:15,097 INFO 20a2baf55f5d4892a9939b223e090e37: Received packet PING data None
2018-04-18 09:26:15,097 INFO 20a2baf55f5d4892a9939b223e090e37: Sending packet PONG data None
2018-04-18 09:26:15,700 INFO 6906fbbacc504f3eb7d71a3091128b79: Received packet PING data None
2018-04-18 09:26:15,700 INFO 6906fbbacc504f3eb7d71a3091128b79: Sending packet PONG data None
2018-04-18 09:26:16,791 INFO 314b59759c4344119b33773a5fded716: Received packet PING data None
2018-04-18 09:26:16,791 INFO 314b59759c4344119b33773a5fded716: Sending packet PONG data None
2018-04-18 09:26:18,345 INFO e1158c58a76643fdb58d749ae5067186: Received packet PING data None
2018-04-18 09:26:18,346 INFO e1158c58a76643fdb58d749ae5067186: Sending packet PONG data None
2018-04-18 09:26:19,745 INFO 1d93e6ed3ba249ee853515e4cf3ab09b: Received packet PING data None
2018-04-18 09:26:19,746 INFO 1d93e6ed3ba249ee853515e4cf3ab09b: Sending packet PONG data None
2018-04-18 09:26:21,657 INFO 337ee328bde54513b049f980c36111ea: Received packet PING data None
2018-04-18 09:26:21,657 INFO 337ee328bde54513b049f980c36111ea: Sending packet PONG data None
2018-04-18 09:26:22,377 INFO 070ccfd6869a4e1db4a237427cc36087: Received packet PING data None
2018-04-18 09:26:22,377 INFO 070ccfd6869a4e1db4a237427cc36087: Sending packet PONG data None
2018-04-18 09:26:22,406 INFO 7cd8939bfcce47c2a91fcc1803439780: Received packet PING data None
2018-04-18 09:26:22,407 INFO 7cd8939bfcce47c2a91fcc1803439780: Sending packet PONG data None

Hello seb-aprolis,

seb-aprolis wrote: ↑Apr 18, 2018 - 09:37 I modified the relevant parameter, but it doesn't change much. However, I have a question: is the time SocketIO uses CEST or UTC?

For me, the clients are sending CEST time (so, in my case, the Paris time zone). Despite setting the signature_clockskew value to 72,000 (i.e., 20 minutes), I still get a message for smaller discrepancies (713 seconds).

Here is an excerpt from the log:
2018-04-18 09:26:05,075 WARNING SocketIO connection refused for uuid 5E56B0BC-659C-11E4-B666-D54C01160E00, sid 9bbed422a96647b09e7012ac3ba53bb3: Data too old or in the future age: 713s...

However, on the PING/PONG requests, I observe that the clients are not sending back anything...

Excerpt from the log:
2018-04-18 09:26:07,944 INFO a4363b4915254ffeb9b8bb2985b6dfc4: Received packet PING data None
2018-04-18 09:26:07,945 INFO a4363b4915254ffeb9b8bb2985b6dfc4: Sending packet PONG data None
2018-04-18 09:26:08,998 INFO 46271366851944f8aa9c2bf7a03549fa: Received packet PING data None
....
2018-04-18 09:26:22,407 INFO 7cd8939bfcce47c2a91fcc1803439780: Sending packet PONG data None

We've seen issues in the past with the Socket.io client not resetting its connection when it loses. One way to force the Socket.io client to reset is to restart Nginx. Could you try stopping Nginx, waiting a few seconds, and then restarting it?

Sincerely,

Denis