Serveur qui tourne au ralenti

Bonjour à tous,

Nous avons un serveur ScenariChain 5 qui tourne au ralenti depuis ce week-end. Il semblerait que ce soit un problème d’espace disque :

/dev/sdi 30G 29G 461M 99% /var/lib/scenari

Et voici en détail ce que nous avons dans ce espace :

20M ./backup
476M ./addons
8.0K ./.config
20G ./data
1.8M ./.cache
16K ./lost+found
9.1G ./working
29G .


jetty@suite-starter-15-z6qw7:~$ cd data/
jetty@suite-starter-15-z6qw7:~/data$ ls -ltra
total 16
drwxrwsr-x. 5 jetty jetty 4096 Mar 9 2021 prl-chain
drwxrwsr-x. 4 jetty jetty 4096 Mar 9 2021 .
drwxrwsr-x. 7 jetty jetty 4096 Jun 1 2021 prl-depot
drwxrwsr-x. 9 root jetty 4096 May 23 2023 ..
jetty@suite-starter-15-z6qw7:~/data$ du -hd1
6.1G ./prl-chain
14G ./prl-depot
20G .

jetty@suite-starter-15-z6qw7:~/data$ ls -ltra
total 16
drwxrwsr-x. 5 jetty jetty 4096 Mar 9 2021 prl-chain
drwxrwsr-x. 4 jetty jetty 4096 Mar 9 2021 .
drwxrwsr-x. 7 jetty jetty 4096 Jun 1 2021 prl-depot
drwxrwsr-x. 9 root jetty 4096 May 23 2023 ..
jetty@suite-starter-15-z6qw7:~/data$ du -hd1
6.1G ./prl-chain
14G ./prl-depot
20G .

jetty@suite-starter-15-z6qw7:~/data$ cd prl-depot/
jetty@suite-starter-15-z6qw7:~/data/prl-depot$ du -hd1
4.0K ./cipher
24K ./stlogs
8.0K ./jobs
14G ./A
88K ./urlTree
14G .

jetty@suite-starter-15-z6qw7:~/data/prl-depot$ cd A/
jetty@suite-starter-15-z6qw7:~/data/prl-depot/A$ du -hd1
7.1G ./views
6.4G ./raws
14G .

On m’a rajouté 5Go sur la partition et relancé le POD (c’est un docker), mais cela ne semble pas mieux se passer.

Les supports sont très lents, exemple : Formation Administrateur ENT

et le backend est inexploitable bien que l’on arrive à s’authentifier.

Je suis preneur de toutes aides… Merci :pray:

il faudrait voir du côté des logs SCENARI. Vous avez alloué combien de RAM à Jetty ?

Sans avoir plus d’information sur la quantité ou le type des donnés stockés dans votre dépôt, les tailles des différents dossiers ne me choque pas.

Merci pour ce début de réponse.

Ce serveur a fonctionné pendant 2 ans sans aucun soucis. Il y a 20 Go de Ram que se partage les pods.

Au niveau des logs, on trouve cela :

jetty@suite-starter-15-djrsx:/var/log/scenari$ cat scstatic_2023-12-11.log
1--- Info : Mon Dec 11 07:52:48 UTC 2023[746] (main) ---
================================================================================
Starting SCENARIsuite-starter 5.0 : SCENARIsuite-starter 5.0.101 202110061212 on OpenJDK 64-Bit Server VM 11.0.13+8-Ubuntu-0ubuntu1.20.04 / Linux amd64


1--- Info : Mon Dec 11 07:52:48 UTC 2023[760] (main) ---
OpenDocument editor found by env. var. 'PATH' in: /usr/lib/libreoffice/program


1--- Info : Mon Dec 11 08:07:47 UTC 2023[853] (main) ---
================================================================================
Starting SCENARIsuite-starter 5.0 : SCENARIsuite-starter 5.0.101 202110061212 on OpenJDK 64-Bit Server VM 11.0.13+8-Ubuntu-0ubuntu1.20.04 / Linux amd64


1--- Info : Mon Dec 11 08:07:47 UTC 2023[864] (main) ---
OpenDocument editor found by env. var. 'PATH' in: /usr/lib/libreoffice/program`

Dans le dossier jetty9, voici la fin de gc.log :


[2023-12-11T10:12:17.200+0000][34][safepoint ] Application time: 84.0106166 seconds
[2023-12-11T10:12:17.200+0000][34][safepoint ] Entering safepoint region: Cleanup
[2023-12-11T10:12:17.200+0000][34][safepoint ] Leaving safepoint region
[2023-12-11T10:12:17.200+0000][34][safepoint ] Total time for which application threads were stopped: 0.0000971 seconds, Stopping threads took: 0.0000216 seconds
[2023-12-11T10:16:19.231+0000][34][safepoint ] Application time: [242.0311083](tel:2420311083) seconds
[2023-12-11T10:16:19.231+0000][34][safepoint ] Entering safepoint region: Cleanup
[2023-12-11T10:16:19.231+0000][34][safepoint ] Leaving safepoint region
[2023-12-11T10:16:19.231+0000][34][safepoint ] Total time for which application threads were stopped: 0.0001582 seconds, Stopping threads took: 0.0000442 seconds
[2023-12-11T10:27:59.380+0000][34][safepoint ] Application time: [700.1488701](tel:7001488701) seconds`

et le 2023_12_11.request.log

10.128.8.1 - - [11/Dec/2023:10:12:17 +0000] "GET /sc/~~static/scCore/fr-FR/-wre/5.0.101.20211006114651/litHtml/lib/part.js HTTP/1.1" 200 834 "https://danescenari.edu.ac-lyon.fr/sc/~~static/scCore/fr-FR/-wre/5.0.101.20211006114651/litHtml/lib/parts.js" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/116.0.0.0 Safari/537.36" 2
10.128.2.1 - - [11/Dec/2023:10:12:17 +0000] "GET /sc/~~static/scCore/fr-FR/-wre/5.0.101.20211006114651/litHtml/lib/template-result.js HTTP/1.1" 200 3502 "https://danescenari.edu.ac-lyon.fr/sc/~~static/scCore/fr-FR/-wre/5.0.101.20211006114651/litHtml/lib/parts.js" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/116.0.0.0 Safari/537.36" 1
10.131.0.1 - - [11/Dec/2023:10:12:17 +0000] "GET /sc/~~static/scCore/fr-FR/-wre/5.0.101.20211006114651/litHtml/lib/default-template-processor.js HTTP/1.1" 200 2055 "https://danescenari.edu.ac-lyon.fr/sc/~~static/scCore/fr-FR/-wre/5.0.101.20211006114651/litHtml/lit-html.js" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/116.0.0.0 Safari/537.36" 1
10.128.2.1 - - [11/Dec/2023:10:27:59 +0000] "GET /sc/pub/CRCN/res/D4_2NivComp.png HTTP/1.1" 200 301548 "https://www.google.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36" 11`

Mon collègue a aussi trouvé ces 2 lignes avec un ps -faux

jetty 1 0.0 0.0 2352 376 ? Ss 08:07 0:00 /usr/bin/dumb-init -- /usr/bin/java -Xms1024m -Xmx1024m -XX:+UseCompresse
jetty 34 0.4 2.4 4676852 489828 ? Ssl 08:07 0:41 /usr/bin/java -Xms1024m -Xmx1024m -XX:+UseCompressedOops -Djava.awt.headl

Mais pas sûr que ce soit éclairant.

On a d’autres informations où chercher ? Je ne trouve pas de docs sur où trouver les journaux.

La RAM alloué à Jetty à son démarrage est défini par JT_JAVA_OPTS, c.f. Docker
Vos instances Docker se partage peut-être 20Go mais le process Java de Jetty non, il utilise ce qu’on lui donne à son démarrage.

Par contre je ne vois rien dans les logs qui donnerait à croire que SCENARIsuite-starter soit en manque de RAM.

Vu de chez moi je trouve que vous avez en effet des problèmes, mais plus de réseau ?

J’ai des latences au chargement des pages, et parfois des échecs du type :
image

Au passage il faudra songer à passer en SCENARIsuite-starter 6

Merci. Je vais voir avec le réseau si c’est un problème de ce type.

Pour SC6, c’est prévu depuis longtemps mais le manque de ressources fait que nous ne pouvons avancer sur ce sujet.

Alors, l’équipe réseau a analysé et n’a rien vu côté réseau général ou sur les pods. Cela semble donc être un problème applicatif.

Y a-t-il du ménage ou des commandes que l’on pourrait passer en ligne de commande pour essayer de résoudre cela ?

Actuellement, on ne peut plus se connecter au backend, et sur les supports web en ligne, on recoit ce type de message :

"Search init failed: ReferenceError: scDynUiMgr is not defined"
"tplMgr init failed: ReferenceError: scDynUiMgr is not defined"

Mode désespéré :sob:

Merci :pray:

Peut importe les différents messages JS côté client. De façon aléatoire on a des erreurs 503 sur tel ou tel ressource, dans votre exemple la requête https://danescenari.edu.ac-lyon.fr/sc/pub/ENT/Admin_ENT_web/lib-sc/scDynUiMgr.js était en 503, si vous faites F5 ce sera autre-chose, ou rien du tout, ou la page HTML elle-même ce qui donne le message que j’ai eu plus haut.

Il faut maintenant comprendre d’où viennent ces messages 503 il faut analyser les logs de Jetty et de scenarisuite-starter pour aller plus loin.

Est-ce que je peux en savoir plus où trouver ces logs car la personne qui a les accès n’est pas du tout spécialiste et je ne suis qu’un intermédiaire :pensive:

Merci !

Les logs SCENARI sont dans le dossier /var/log/scenarisuite-starter5.0 ou on trouve un fichier par jour nommé comme suit : scstatic_2023-12-11.log
Il y a des chances que les logs Jetty sont dans le fichier /var/log/syslog, une commande comme grep jetty9 /var/log/syslog | less devrait montrer les logs Jetty mais cela dépends de comment Jetty a été configuré.

ensuite je ne sais pas comment vous avez paramétré l’accès HTTPS au serveur de servlet (Nginx ? Apache ?) il faudrait aussi voir ce qui ressors dans leurs logs et leurs accesslogs.

Merci pour le retour @sam .

Il faut savoir que nous utilisons l’image Docker que @anp nous avait crée il y a déjà quelques années. Donc, nous n’avons pas tous les logs dans l’image.

J’ai mis les fichiers de log derrière ce lien. Je n’ai rien d’anormal hormis une erreur sur les gif anim mais c’était déjà existant.

En revanche, quand on a démarré le pod, on a eu cela :

Example reverse proxy: https://danescenari.edu.ac-lyon.fr/sc => http://CONTAINER_IP:PUBLISH_PORT/sc
2023-12-12 08:16:53.401:INFO::main: Logging initialized @824ms to org.eclipse.jetty.util.log.StdErrLog
2023-12-12 08:16:53.925:INFO:oejs.Server:main: jetty-9.4.26.v20200117; built: unknown; git: unknown; jvm 11.0.13+8-Ubuntu-0ubuntu1.20.04
2023-12-12 08:16:53.955:INFO:oejdp.ScanningAppProvider:main: Deployment monitor [file:///var/lib/jetty9/webapps/] at interval 1
2023-12-12 08:16:55.885:INFO:oeja.AnnotationConfiguration:main: Scanning elapsed time=0ms
2023-12-12 08:16:55.899:INFO:oejw.StandardDescriptorProcessor:main: NO JSP Support for /sc, did not find org.eclipse.jetty.jsp.JettyJspServlet
2023-12-12 08:16:56.071:INFO:oejs.session:main: DefaultSessionIdManager workerName=node0
2023-12-12 08:16:56.071:INFO:oejs.session:main: No SessionScavenger set, using defaults
2023-12-12 08:16:56.072:INFO:oejs.session:main: node0 Scavenging every 600000ms
2023-12-12 08:16:57.898:INFO:oejsh.ContextHandler:main: Started o.e.j.w.WebAppContext@707194ba{sc,/sc,file:///tmp/jetty-0_0_0_0-8080-sc_war-_sc-any-11219609305025747473.dir/webapp/,AVAILABLE}{/var/lib/jetty9/webapps/sc.war}
2023-12-12 08:16:57.907:INFO:oejs.RequestLogWriter:main: Opened /var/log/jetty9/2023_12_12.request.log
2023-12-12 08:16:57.937:INFO:oejs.AbstractConnector:main: Started ServerConnector@711d1a52{HTTP/1.1,[http/1.1]}{0.0.0.0:8080}
2023-12-12 08:16:57.938:INFO:oejs.Server:main: Started @5361ms`

Je pense que tout est normal car je viens de comparer avec une autre install Docker et j’ai exactement les mêmes messages.

Enfin, l’espace disque semble ok :

overlay 20G 16G 4.9G 76% /
tmpfs 9.8G 0 9.8G 0% /dev
tmpfs 9.8G 0 9.8G 0% /sys/fs/cgroup
/dev/sdc 20G 34M 20G 1% /etc/hosts
shm 64M 0 64M 0% /dev/shm
/dev/sdb 20G 16G 4.9G 76% /run/secrets
/dev/sdn 35G 29G 5.4G 85% /var/lib/scenari
/dev/sdi 2.0G 30M 1.9G 2% /var/log/scenari
tmpfs 9.8G 16K 9.8G 1% /run/secrets/[kubernetes.io/serviceaccount](http://kubernetes.io/serviceaccount)
tmpfs 9.8G 0 9.8G 0% /proc/acpi
tmpfs 9.8G 0 9.8G 0% /proc/scsi
tmpfs 9.8G 0 9.8G 0% /sys/firmware`

Et on a rajouté 2 Go de RAM pour le POD…

Dernière précision, un collègue a réussi à extraire des .scar des cours en limitant, dans les options développeurs de Chromium, la bande passante à 50 Ko. Bref, tout est bizarre et on ne sait plus où chercher :sob:

Bonjour @Bristow ,

J’imagine que le fichier « 2023_12_12.request » correspond aux accesslog de Jetty. Je n’y vois aucune requete en 503 là dedans.
Pouvez-vous joindre l’accesslog du reverseProxy (nginx ?) ?

Cdt
Antoine

1 « J'aime »

Je t’ai envoyé en privé des logs du HAProxy.

Coté client, voici les 503 que l’on obtient :

merci :pray:

Bonjour @Bristow ,
On voit dans ces logs les entrées correspondant à ces 503 aléatoires :

46004 [14/Dec/2023:09:29:43.021] f_192_168_239_90_443~ b_tube/ocs3-nodehbg-12 1/0/0/12007/12010 503 3278 - - ---- 126/96/14/2/0 0/0 « GET /sc/~~static/scCore/fr-FR/-wlb/5.0.101.20211006114651/core/user.js HTTP/1.1 »

Tu peux regarder dans les logs de jetty, pour le même horodatage « 14/Dec/2023:09:29:43.021 », ce que retourne la requête sur /sc/~~static/scCore/fr-FR/-wlb/5.0.101.20211006114651/core/user.js ?

Si c’est bien 200, cela confirmera un pb sur votre reverse proxy « HAProxy ». Retour du ticket à l’équipe réseau donc ! (je ne connais pas HAProxy, mais il y a très certainement un fichier de logs d’erreurs)

Antoine
Kelis

Bon… On a enfin trouvé la cause du soucis, je le mets ici car cela peut arriver à d’autres je pense.

C’était un problème de routage interne dans l’openshift, un node semble avoir eu un problème.

Bref, c’est réglé. Merci à @sam et @anp pour le soutien et les pistes… Je précise que le serveur avait parfaitement fonctionné durant plusieurs années sans aucun soucis :heart_decoration:

Super que le réseau ait pu identifier/corriger le pb !

Je me permets de vraiment insister : la vieille version 5.0 est maintenant en statut « fin de vie » (cf versions-scenari

Pour des environnements en production, qui veulent bénéficier des correctifs et des mises à jour de sécurité, il n’est donc plus possible de reculer le passage en 6.2 (ou 6.1).

C’est pourquoi j’ai ouvert ce fil :wink: Mise à jour vers les dernières versions

1 « J'aime »