Service Error : HTTP 500

Service Error : HTTP 500
0
Tags: #<Tag:0x00007fec61cf4d38>

Bonjour,

Je rencontre une erreur de type Service Error : HTTP 500 à chaque fois où je veux modifier et enregistrer mon code. Je ne peux également faire des opérations git.

Je ne trouve aucune trace de l’erreur dans les log système.
Healthcheck de mon instance :

[Platform]
Status=OK
Version=4.0.P24
BuiltOn=2020-05-19 22:06 (revision 25ed8fe0efec3d050cf138472f7fff72ece375da)
Encoding=UTF-8
EndpointIP=172.19.0.4
EndpointURL=http://fa885813f732:8080
TimeZone=UTC
SystemDate=2020-05-20 04:46:23

[Application]
ApplicationVersion=4.0
ContextPath=
ContextURL=https://simplicite.mineralconseil.fr
ActiveSessions=2
TotalUsers=20
EnabledUsers=10
LastLoginDate=

[Server]
ServerInfo=Apache Tomcat/9.0.35
ServerType=WEB
User=root

[OS]
Name=Linux
Architecture=amd64
Version=3.10.0-1062.12.1.el7.x86_64
SystemEncoding=UTF-8

[Disk]
DiskFree=71563
DiskUsable=71563
DiskTotal=81908

[JavaVM]
Version=14
Vendor=N/A
VMName=OpenJDK 64-Bit Server VM
VMVersion=14+36
ScriptEngine=rhino
ScriptEngineVersion=Rhino 1.7.11 2019 05 30
HeapFree=114777
HeapSize=220160
HeapMaxSize=970752
TotalFreeSize=865369

[Cache]
GrantCache=19
GrantCacheMax=0
GrantCacheRatio=0
ObjectCache=194
ObjectCacheMax=10000
ObjectCacheRatio=1
ProcessCache=1
ProcessCacheMax=10000
ProcessCacheRatio=0

[Database]
Vendor=3
ProductName=PostgreSQL
ProductVersion=12.2 (Debian 12.2-2.pgdg100+1)
DriverName=PostgreSQL JDBC Driver
DriverVersion=42.2.12
DBDate=2020-05-20 04:46:23
DBDateOffset=0
DBPatchLevel=P24;dd4ae8051d0d7385e80e790fb13162a2
UsingBLOBs=true

[Healthcheck]
Date=2020-05-20 04:46:23
ElapsedTime=4

Avez-vous une idée de la source du problème ?
D’avance merci.

Comment est installé cette instance (je pose la question car je soupçonne des pbs de droits d’écriture sur les répertoires de travail) ?

L’instance est installée en conteneur docker via docker compose.
Le fichier docker-compose.yml

version: "3"
services:
  db:
    image: postgres:latest
    restart: always
    container_name: myinstance-postgres-database
    environment:
      - POSTGRES_USER= user
      - POSTGRES_PASSWORD= pass
      - POSTGRES_DB= dbname
    ports:
    - 127.17.0.1:5432:5432
    volumes:
    - myinstance-postgres-db:/var/lib/postgresql/data
  wkhtml2pdf:
    image: openlabs/docker-wkhtmltopdf-aas:latest
    restart: always
  web:
    image: simplicite/platform:latest
    restart: always
    container_name: defilippis-prod-app
    environment:
      DB_SETUP: "true"
      DB_VENDOR: "postgresql"
      DB_HOST: db
      DB_USER: "user"
      DB_PASSWORD: "pass"
      DB_NAME: "dbname"
      DB_WAIT: 10
    ports:
     - 8443:8443
    volumes:
    - myinstance-postgres-git:/usr/local/tomcat/webapps/ROOT/WEB-INF/git
    - ./.well-known:/usr/local/tomcat/webapps/ROOT/.well-known
    - /etc/letsencrypt/live/simplicite.mineralconseil.fr/fullchain.pem:/etc/ssl/server.crt
    - /etc/letsencrypt/live/simplicite.mineralconseil.fr/privkey.pem:/etc/ssl/server.key
    depends_on:
    - db
    
volumes:
  myinstance-postgres-db:
  myinstance-postgres-git:

OK je ne vois à priori rien dans ce fichier compose qui pourrait expliquer le pb décrit.

Il doit forcément y avoir des infos/stacktraces dans les logs serveur, allez voir directement dans le container:

  • connectez vous à votre container sudo docker exec -it <container ID / name> bash
  • Logs Tomcat = /usr/local/tomcat/logs/catalina.out
  • Logs Simplicite = /usr/local/tomcat/webapps/ROOT/WEB-INF/log/simplicite.log

C’est ce que j’obtiens comme derniers logs des deux fichiers.

simplicite.log

2020-05-20 06:55:02,681 INFO  [com.simplicite.util.engine.CronManager] SIMPLICITE|http://fa885813f732:8080||INFO|system|com.simplicite.util.engine.CronManager|run||Evénement: Next cron job: ImportXML at Wed May 20 07:00:00 UTC 2020
2020-05-20 06:55:02,681 INFO  [com.simplicite.util.engine.CronManager] SIMPLICITE|http://fa885813f732:8080||INFO|system|com.simplicite.util.engine.CronManager|run||Evénement: Next cron job: deadlineProcess at Wed May 20 07:00:00 UTC 2020
2020-05-20 06:55:02,682 INFO  [com.simplicite.util.engine.CronManager] SIMPLICITE|http://fa885813f732:8080||INFO|system|com.simplicite.util.engine.CronManager|run||Evénement: Next cron job: ClearUserTokens at Wed May 20 07:00:00 UTC 2020
2020-05-20 06:55:02,682 INFO  [com.simplicite.util.engine.CronManager] SIMPLICITE|http://fa885813f732:8080||INFO|system|com.simplicite.util.engine.CronManager|run||Evénement: Next cron job: deadlineActivity at Wed May 20 07:00:00 UTC 2020
2020-05-20 06:55:02,682 INFO  [com.simplicite.util.engine.CronManager] SIMPLICITE|http://fa885813f732:8080||INFO|system|com.simplicite.util.engine.CronManager|run||Evénement: Next cron job: deadlockActivity at Wed May 20 07:00:00 UTC 2020
2020-05-20 06:55:02,682 INFO  [com.simplicite.util.engine.CronManager] SIMPLICITE|http://fa885813f732:8080||INFO|system|com.simplicite.util.engine.CronManager|run||Evénement: Next cron job: deadlineState at Wed May 20 07:00:00 UTC 2020
2020-05-20 06:55:02,682 INFO  [com.simplicite.util.engine.CronManager] SIMPLICITE|http://fa885813f732:8080||INFO|system|com.simplicite.util.engine.CronManager|run||Evénement: Cron manager is sleeping for 0:04:57...
2020-05-20 06:55:02,995 INFO  [com.simplicite.util.engine.Platform] SIMPLICITE|http://fa885813f732:8080||PLATFORM|system|com.simplicite.util.engine.Platform|removeNode||Unregistered node = http://fa885813f732:8080
2020-05-20 06:55:03,004 INFO  [com.simplicite.util.engine.CronManager] SIMPLICITE|http://fa885813f732:8080||ICORECM002|system|com.simplicite.util.engine.CronManager|stop||Le processus de gestion de la Cron a été arrêté à Wed May 20 06:55:03 UTC 2020
2020-05-20 06:55:03,012 INFO  [com.simplicite.util.engine.CronManager$CronDaemon] SIMPLICITE|http://fa885813f732:8080||INFO|system|com.simplicite.util.engine.CronManager$CronDaemon|run||Evénement: The cron manager has been interrupted.

catalina.out

20-May-2020 06:55:02.733 INFO [main] org.apache.catalina.core.StandardService.stopInternal Stopping service [Catalina]
20-May-2020 06:55:02.962 INFO [main] com.simplicite.util.AppLog.globalLog SIMPLICITE: Platform on endpoint [http://fa885813f732:8080] is stopping...
2020-05-20 06:55:02,995|SIMPLICITE|http://fa885813f732:8080||PLATFORM|system|com.simplicite.util.engine.Platform|removeNode||Unregistered node = http://fa885813f732:8080
2020-05-20 06:55:03,004|SIMPLICITE|http://fa885813f732:8080||ICORECM002|system|com.simplicite.util.engine.CronManager|stop||Le processus de gestion de la Cron a été arrêté à Wed May 20 06:55:03 UTC 2020
20-May-2020 06:55:03.004 INFO [main] com.simplicite.util.AppLog.globalLog SIMPLICITE: Platform on endpoint [http://fa885813f732:8080] stopped
2020-05-20 06:55:03,012|SIMPLICITE|http://fa885813f732:8080||INFO|system|com.simplicite.util.engine.CronManager$CronDaemon|run||Evénement: The cron manager has been interrupted.
20-May-2020 06:55:03.067 INFO [main] org.apache.coyote.AbstractProtocol.stop Stopping ProtocolHandler ["http-nio-8080"]
20-May-2020 06:55:03.067 INFO [main] org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler ["http-nio-8080"]
20-May-2020 06:55:03.067 INFO [main] org.apache.coyote.AbstractProtocol.stop Stopping ProtocolHandler ["http-nio-8443"]
20-May-2020 06:55:03.067 INFO [main] org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler ["http-nio-8443"]

Ces logs partiels n’ont strictement aucun rapport avec les actions que vous décrivez (enregistrement du code d’un objet ou actions Git sur les modules).

Merci de nous fournir des éléments pertinents et le contexte précis de vos problèmes car là, avec les informations fournies, on ne peut vraiment rien investiguer.

NB: Par acquis de conscience nous avons réalisé une installation similaire et nous n’avons pas les pb que vous indiquez.

J’ai utilisé un grep pour chercher l’erreur dans les textes des logs et aucune correspondance n’a été trouvée.
Les logs partiels que j’ai fourni sont les plus récents après actualisation du code et obtention de l’erreur.

Sans des logs pertinentes ou, au moins, des infos précises de contexte (= une description de votre mode opératoire étape par étape, avec des copies d’écran, idéalement avec les dev tools de votre navigateur ouverts sur l’onglet console et/ou network, etc.) votre pb ne peut tout simplement pas être investigué.

Ex: dire “Je ne peux également faire des opérations git.” ça ne veut strictement rien dire: quelle opérations ? sur quel module ? avec quels settings du Module ? etc.

Pour solliciter notre support il faut nous fournir des éléments précis car, sans ça, on ne peut pas deviner ce que vous ne dites pas. Il me semble vous avoir déjà dit ça.

Une autre information à mentionner :
l’instance passe par un reverse proxy nginx de la configuration suivante :

/etc/nginx/nginx.conf

user nginx;
worker_processes auto;
error_log /var/log/nginx/error.log;
pid /run/nginx.pid;

# Load dynamic modules. See /usr/share/doc/nginx/README.dynamic.
include /usr/share/nginx/modules/*.conf;

events {
    worker_connections 1024;
}

http {
    log_format  main  '$remote_addr - $remote_user [$time_local] "$request" '
                      '$status $body_bytes_sent "$http_referer" '
                      '"$http_user_agent" "$http_x_forwarded_for"';

    access_log  /var/log/nginx/access.log  main;

    sendfile            on;
    tcp_nopush          on;
    tcp_nodelay         on;
    keepalive_timeout   65;
    types_hash_max_size 2048;

    include             /etc/nginx/mime.types;
    default_type        application/octet-stream;

    # Load modular configuration files from the /etc/nginx/conf.d directory.
    # See http://nginx.org/en/docs/ngx_core_module.html#include
    # for more information.
    include /etc/nginx/conf.d/*.conf;

    server {
        listen       80;
        listen       [::]:80;
        server_name  simplicite.mineralconseil.fr;

        location ^~/.well-known/acme-challenge/ {
                #allow all;
                root /usr/local/tomcat/webapps/ROOT;
        }
        location / {
                return 301 https://simplicite.mineralconseil.fr$request_uri;
        }

        error_page 404 /404.html;
            location = /40x.html {
        }

        error_page 500 502 503 504 /50x.html;
            location = /50x.html {
        }
    }

# Settings for a TLS enabled server.
#
  server {
        listen       443 ssl http2;
        listen       [::]:443 ssl http2;
        server_name  simplicite.mineralconseil.fr;

	ssl_certificate /etc/letsencrypt/live/simplicite.mineralconseil.fr/fullchain.pem;
    	ssl_certificate_key /etc/letsencrypt/live/simplicite.mineralconseil.fr/privkey.pem;

    	location / {
        	if ($request_method = 'OPTIONS') {
            		add_header Access-Control-Allow-Origin $http_origin;
            		add_header Access-Control-Allow-Credentials true;
            		add_header Access-Control-Allow-Headers Content-Type,Authorization,X-Requested-With,X-HTTP-Method-Override,X-Simplicite-Authorization;
            		add_header Access-Control-Allow-Methods GET,POST,PUT,DELETE,HEAD,OPTIONS;
            		add_header Access-Control-Max-Age 1728000;
            		add_header Content-Type text/plain;
            		add_header Content-Length 0;
            		return 204;
        	}
        	if ($request_method = 'GET') {
            		add_header Access-Control-Allow-Origin $http_origin always;
            		add_header Access-Control-Allow-Credentials true always;
            		add_header Access-Control-Expose-Headers X-Simplicite-SessionID;
        	}
        	if ($request_method = 'POST') {
            		add_header Access-Control-Allow-Origin $http_origin always;
          	 	add_header Access-Control-Allow-Credentials true always;            
                        add_header Access-Control-Expose-Headers X-Simplicite-SessionID;        	
                }		        	

            proxy_redirect off;
        	proxy_buffering off;
        	proxy_read_timeout 86400s;
        	proxy_send_timeout 86400s;
        	proxy_set_header Host $http_host;
        	proxy_set_header X-Real-IP $remote_addr;
        	proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
        	proxy_set_header X-Forwarded-Proto https;
        	proxy_pass http://localhost:8443;
        	proxy_http_version 1.1;
        	proxy_set_header Upgrade $http_upgrade;
        	proxy_set_header Connection "upgrade";
    }

}
}


en vérifiant le fichier : /var/log/nginx/error.log j’obtiens les traces suivantes


2020/05/20 09:44:18 [crit] 20157#0: *1 open() "/var/lib/nginx/tmp/client_body/0000000001" failed (13: Permission denied), client: 90.44.153.144, server: simplicite.mineralconseil.fr, request: "POST /ui/json/app?action=editor&srv=save&object=ObjectInternal&rowid=2030&field=obo_script_id&scope=object&type=java&selected=ObjectInternal_obo_script_id_2030&_=25ed8fe0efec3d050cf138472f7fff72ece375da_20200520035700 HTTP/2.0", host: "simplicite.mineralconseil.fr", referrer: "https://simplicite.mineralconseil.fr/ui"
2020/05/20 09:46:43 [error] 20156#0: *379 connect() failed (111: Connection refused) while connecting to upstream, client: 90.44.153.144, server: simplicite.mineralconseil.fr, request: "GET /ui/events HTTP/1.1", upstream: "http://127.0.0.1:8443/ui/events", host: "simplicite.mineralconseil.fr"
2020/05/20 09:46:43 [error] 20156#0: *379 connect() failed (111: Connection refused) while connecting to upstream, client: 90.44.153.144, server: simplicite.mineralconseil.fr, request: "GET /ui/events HTTP/1.1", upstream: "http://[::1]:8443/ui/events", host: "simplicite.mineralconseil.fr"
2020/05/20 09:46:45 [error] 20157#0: *382 connect() failed (111: Connection refused) while connecting to upstream, client: 90.44.153.144, server: simplicite.mineralconseil.fr, request: "GET /ui/events HTTP/1.1", upstream: "http://127.0.0.1:8443/ui/events", host: "simplicite.mineralconseil.fr"
2020/05/20 09:46:45 [error] 20157#0: *382 connect() failed (111: Connection refused) while connecting to upstream, client: 90.44.153.144, server: simplicite.mineralconseil.fr, request: "GET /ui/events HTTP/1.1", upstream: "http://[::1]:8443/ui/events", host: "simplicite.mineralconseil.fr"
2020/05/20 09:46:49 [error] 20157#0: *385 no live upstreams while connecting to upstream, client: 90.44.153.144, server: simplicite.mineralconseil.fr, request: "GET /ui/events HTTP/1.1", upstream: "http://localhost/ui/events", host: "simplicite.mineralconseil.fr"
2020/05/20 09:46:57 [error] 20157#0: *386 connect() failed (111: Connection refused) while connecting to upstream, client: 90.44.153.144, server: simplicite.mineralconseil.fr, request: "GET /ui/events HTTP/1.1", upstream: "http://[::1]:8443/ui/events", host: "simplicite.mineralconseil.fr"
2020/05/20 09:46:57 [error] 20157#0: *386 connect() failed (111: Connection refused) while connecting to upstream, client: 90.44.153.144, server: simplicite.mineralconseil.fr, request: "GET /ui/events HTTP/1.1", upstream: "http://127.0.0.1:8443/ui/events", host: "simplicite.mineralconseil.fr"
2020/05/20 09:47:12 [error] 20157#0: *390 connect() failed (111: Connection refused) while connecting to upstream, client: 90.44.153.144, server: simplicite.mineralconseil.fr, request: "GET /ui/events HTTP/1.1", upstream: "http://[::1]:8443/ui/events", host: "simplicite.mineralconseil.fr"
2020/05/20 09:47:12 [error] 20157#0: *390 connect() failed (111: Connection refused) while connecting to upstream, client: 90.44.153.144, server: simplicite.mineralconseil.fr, request: "GET /ui/events HTTP/1.1", upstream: "http://127.0.0.1:8443/ui/events", host: "simplicite.mineralconseil.fr"
2020/05/20 09:48:10 [crit] 20157#0: *389 open() "/var/lib/nginx/tmp/client_body/0000000002" failed (13: Permission denied), client: 90.44.153.144, server: simplicite.mineralconseil.fr, request: "POST /ui/json/app?action=editor&srv=save&object=ObjectInternal&rowid=2033&field=obo_script_id&scope=object&type=java&selected=ObjectInternal_obo_script_id_2033&_=25ed8fe0efec3d050cf138472f7fff72ece375da_20200520094425 HTTP/2.0", host: "simplicite.mineralconseil.fr", referrer: "https://simplicite.mineralconseil.fr/ui"
2020/05/20 09:48:12 [crit] 20157#0: *389 open() "/var/lib/nginx/tmp/client_body/0000000003" failed (13: Permission denied), client: 90.44.153.144, server: simplicite.mineralconseil.fr, request: "POST /ui/json/app?action=editor&srv=save&object=ObjectInternal&rowid=2023&field=obo_script_id&scope=object&type=java&selected=ObjectInternal_obo_script_id_2023&_=25ed8fe0efec3d050cf138472f7fff72ece375da_20200520094425 HTTP/2.0", host: "simplicite.mineralconseil.fr", referrer: "https://simplicite.mineralconseil.fr/ui"
2020/05/20 09:48:15 [crit] 20157#0: *389 open() "/var/lib/nginx/tmp/client_body/0000000004" failed (13: Permission denied), client: 90.44.153.144, server: simplicite.mineralconseil.fr, request: "POST /ui/json/app?action=editor&srv=save&object=ObjectInternal&rowid=2024&field=obo_script_id&scope=object&type=java&selected=ObjectInternal_obo_script_id_2024&_=25ed8fe0efec3d050cf138472f7fff72ece375da_20200520094425 HTTP/2.0", host: "simplicite.mineralconseil.fr", referrer: "https://simplicite.mineralconseil.fr/ui"
2020/05/20 09:48:18 [crit] 20157#0: *389 open() "/var/lib/nginx/tmp/client_body/0000000005" failed (13: Permission denied), client: 90.44.153.144, server: simplicite.mineralconseil.fr, request: "POST /ui/json/app?action=editor&srv=save&object=ObjectInternal&rowid=2033&field=obo_script_id&scope=object&type=java&selected=ObjectInternal_obo_script_id_2033&_=25ed8fe0efec3d050cf138472f7fff72ece375da_20200520094425 HTTP/2.0", host: "simplicite.mineralconseil.fr", referrer: "https://simplicite.mineralconseil.fr/ui"
2020/05/20 09:53:04 [crit] 20156#0: *450 open() "/var/lib/nginx/tmp/client_body/0000000006" failed (13: Permission denied), client: 90.44.153.144, server: simplicite.mineralconseil.fr, request: "POST /ui/json/app?action=editor&srv=save&object=ObjectInternal&rowid=2033&field=obo_script_id&scope=object&type=java&selected=ObjectInternal_obo_script_id_2033&_=25ed8fe0efec3d050cf138472f7fff72ece375da_20200520094425 HTTP/2.0", host: "simplicite.mineralconseil.fr", referrer: "https://simplicite.mineralconseil.fr/ui"

Problème résolu en changeant les permissions du répertoire /var/lib/nginx/tmp/client_body

Merci

Tant mieux, ce n’était donc pas un pb Simplicité, franchement je ne voyais pas de quoi il pouvait s’agir.

Ce pb de config NGINX ne me dit rien, sur nos reverse proxies NGINX on a jamais un eu un pb comme celui là. Cette doc https://docs.simplicite.io/documentation/90-operation/docker-tutorial.md#nginx indique comment déployer un reverse proxy NGINX directement depuis son docker-compose.yml ça évite les pbs d’install/config de NGINX sur la machine hôte…

Bon en tout cas ça prouve bien qu’il y a toujours une log quelque part où se trouve la raison d’un pb ;-)