Contactez nous

SocketIO : Data too old or in the futur age

Question about WAPT Server / Requêtes et aides autour du serveur Wapt
Règles du forum

* Questions can be asked in English or in French. If the thread is started in English, stick to English, if it is started in French, stick to French.
* Vous pouvez poser vos questions en Français ou en Anglais. Si un sujet est commencé en français, merci de répondre en français. Si un sujet est commencé en anglais, merci de répondre en anglais.

- Version de WAPT installée : 1.5.1.23
- OS du serveur : Debian 9
- OS de la machine d'administration/création des paquets : Windows 10

Bonjour,

Depuis quelques temps notre serveur WAPT ne remonte plus l'information de disponibilité de certaines machines (à vrai dire la majorité). Ce qui est incompréhensible, c'est que certaines d'entre-elles n'ont aucuns problèmes.

Je viens d'effectuer un upgrade du serveur de la version 1.5.1.21 > 1.5.1.23, j'obtiens le même message quand je tente d'uploader le nouvel agent.

En lançant le serveur en mode debug voici ce que j'obtiens :

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 futur 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%2BCVdMm2H2NM8OG5z1UB2Fq8AEjIQ55jTWlw%2FBG7W5rGaNT%2Bks5%2BN647M3E0LApRYSXmvW7x85%2BPz%2B%2BJnyRfqcKf4PujofC8QejzuXYaijA01F2TDzA%2BDiAuIR0SjlOOPl3xlr8a%2Bs8nw%2FcQ%2BJb0A9%2Ft3Assgfse6sqUTbN2PaYxFBKcjrxc3%2FyzdaNUtVenNFVfIbP0LdlgnxRTwgGRPGKLJ5haY3UzMuJaajusB2CAaOHr6YQ%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 [...]
Bonjour seb-aprolis,
seb-aprolis a écrit :
17 avril 2018, 15:27
...
Depuis quelques temps notre serveur WAPT ne remonte plus l'information de disponibilité de certaines machines (à vrai dire la majorité). Ce qui est incompréhensible, c'est que certaines d'entre-elles n'ont aucuns problèmes.

Je viens d'effectuer un upgrade du serveur de la version 1.5.1.21 > 1.5.1.23, j'obtiens le même message quand je tente d'uploader le nouvel agent.

En lançant le serveur en mode debug voici ce que j'obtiens :
B810-0F11F5150E00, sid f520a971bf9c4b7e962a6f97292ee0a7: Data too old or in the futur age : 514s...[/color][/b]
...
est ce que vous pourriez vérifier l'heure sur le serveur et sur les machines clients. Par défaut WAPT accepte au maximum un décalage de 5 minutes entre le serveur et le poste client. Cette tolérance peut être augmenter avec le paramètre signature_clockskew dans le fichier waptserver.ini :

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

Cordialement,

Denis
Merci pour ta réponse Denis.

J'ai modifié le paramètre concerné, mais ça ne change pas grand chose. Par contre, je me pose une question, l'heure qu'utilise SocketIO est l'heure CEST ou l'heure UTC ?

Pour moi les clients envoi l'heure CEST (donc sur le fuseau horaire de Paris dans mon cas). Malgré le fait d'avoir paramétré la valeur signature_clockskew à 72 000 (soit 20 minutes) j'obtiens tout de même un message pour des écarts inférieurs (713 s).

Voici un extrait du 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 futur age : 713s...


Par contre, sur les PING / PONG je constate que les clients ne renvoient rien ...

Extrait du 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
Bonjour seb-aprolis,
seb-aprolis a écrit :
18 avril 2018, 09:37
J'ai modifié le paramètre concerné, mais ça ne change pas grand chose. Par contre, je me pose une question, l'heure qu'utilise SocketIO est l'heure CEST ou l'heure UTC ?

Pour moi les clients envoi l'heure CEST (donc sur le fuseau horaire de Paris dans mon cas). Malgré le fait d'avoir paramétré la valeur signature_clockskew à 72 000 (soit 20 minutes) j'obtiens tout de même un message pour des écarts inférieurs (713 s).

Voici un extrait du 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 futur age : 713s...

Par contre, sur les PING / PONG je constate que les clients ne renvoient rien ...

Extrait du 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
On a vu dans le passé des soucis avec le client socketio qui ne ré-initialisait pas sa connexion quand celle ci n'est plus bonne. Une manière de forcer la ré-initialisation du client socketio est notamment de relancer Nginx. Est ce que tu pourrais tester d'arrêter le Nginx, attendre quelques dizaines de secondes et le relancer?

Cordialement,

Denis