Hi, I'm trying to get this running on my machine running homeassistant But I keep

I do seem to be getting some errors here: <div class="snippet-clipboard-content no

Error 502 bad gateway,about exadel-inc/compreface

Comments (22)

pospielov commented on May 22, 2024 2

hope it won't reproduce anymore :)

from compreface.

pospielov commented on May 22, 2024

Hi, this error mostly occurs when one of the services haven't run correctly
Could you run docker ps and show the results?
In most cases the problem is with compreface-core container could you run docker logs compreface-core and put the logs somewhere?

from compreface.

ferbulous commented on May 22, 2024

docker logs compreface-core
Hi, this is the logs

 docker logs compreface-core
SIGINT/SIGQUIT received...killing workers...
worker 1 buried after 7 seconds
worker 2 buried after 8 seconds
goodbye to uWSGI.
[uWSGI] getting INI configuration from uwsgi.ini
*** Starting uWSGI 2.0.19 (64bit) on [Sat Oct 16 14:55:02 2021] ***
compiled with version: 8.3.0 on 29 August 2021 14:21:15
os: Linux-4.19.0-18-amd64 #1 SMP Debian 4.19.208-1 (2021-09-29)
nodename: d729f1092497
machine: x86_64
clock source: unix
detected number of CPU cores: 2
current working directory: /app/ml
detected binary path: /usr/local/bin/uwsgi
!!! no internal routing support, rebuild with pcre support !!!
setgid() to 33
setuid() to 33
your memory page size is 4096 bytes
detected max file descriptor number: 1048576
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uwsgi socket 0 bound to TCP address 0.0.0.0:3000 fd 3
Python version: 3.7.10 (default, Jun 23 2021, 15:44:41)  [GCC 8.3.0]
Python main interpreter initialized at 0x563f3f3d92f0
python threads support enabled
your server socket listen backlog is limited to 100 connections
your mercy for graceful operations on workers is 60 seconds
mapped 218712 bytes (213 KB) for 2 cores
*** Operational MODE: preforking ***
{"severity": "DEBUG", "message": "Falling back to TensorFlow client; we recommended you install the Cloud TPU client directly with pip install cloud-tpu-client.", "request": null, "logger": "tensorflow", "module": "tpu_cluster_resolver", "traceback": "Traceback (most recent call last):\n  File \"/usr/local/lib/python3.7/site-packages/tensorflow/python/distribute/cluster_resolver/tpu/tpu_cluster_resolver.py\", line 33, in <module>\n    from cloud_tpu_client import client  # pylint: disable=g-import-not-at-top\nModuleNotFoundError: No module named 'cloud_tpu_client'\n", "build_version": "dev"}
{"severity": "DEBUG", "message": "Creating converter from %s to %s", "request": null, "logger": "h5py._conv", "module": "__init__", "traceback": null, "build_version": "dev"}
{"severity": "DEBUG", "message": "Creating converter from %s to %s", "request": null, "logger": "h5py._conv", "module": "__init__", "traceback": null, "build_version": "dev"}
{"severity": "DEBUG", "message": "Creating converter from %s to %s", "request": null, "logger": "h5py._conv", "module": "__init__", "traceback": null, "build_version": "dev"}
{"severity": "DEBUG", "message": "Creating converter from %s to %s", "request": null, "logger": "h5py._conv", "module": "__init__", "traceback": null, "build_version": "dev"}
{"severity": "INFO", "message": "{'BUILD_VERSION': 'dev', 'CALCULATION_PLUGIN': 'facenet.Calculator', 'EXTRA_PLUGINS': ['facenet.LandmarksDetector', 'agegender.AgeDetector', 'agegender.GenderDetector', 'facenet.facemask.MaskDetector'], 'FACE_DETECTION_PLUGIN': 'facenet.FaceDetector', 'GPU_IDX': -1, 'IMG_LENGTH_LIMIT': 640, 'INTEL_OPTIMIZATION': False, 'IS_DEV_ENV': False, 'LOGGING_LEVEL_NAME': 'DEBUG', 'ML_PORT': 3000}", "request": null, "logger": "src.app", "module": "app", "traceback": null, "build_version": "dev"}
{"severity": "DEBUG", "message": "Creating new app for WSGI", "request": null, "logger": "src.app", "module": "app", "traceback": null, "build_version": "dev"}
WSGI app 0 (mountpoint='') ready in 14 seconds on interpreter 0x563f3f3d92f0 pid: 1 (default app)
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI master process (pid: 1)
spawned uWSGI worker 1 (pid: 12, cores: 1)
spawned uWSGI worker 2 (pid: 13, cores: 1)
root@t530:/home/ferbulous# docker logs compreface-core
SIGINT/SIGQUIT received...killing workers...
worker 1 buried after 7 seconds
worker 2 buried after 8 seconds
goodbye to uWSGI.
[uWSGI] getting INI configuration from uwsgi.ini
*** Starting uWSGI 2.0.19 (64bit) on [Sat Oct 16 14:55:02 2021] ***
compiled with version: 8.3.0 on 29 August 2021 14:21:15
os: Linux-4.19.0-18-amd64 #1 SMP Debian 4.19.208-1 (2021-09-29)
nodename: d729f1092497
machine: x86_64
clock source: unix
detected number of CPU cores: 2
current working directory: /app/ml
detected binary path: /usr/local/bin/uwsgi
!!! no internal routing support, rebuild with pcre support !!!
setgid() to 33
setuid() to 33
your memory page size is 4096 bytes
detected max file descriptor number: 1048576
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uwsgi socket 0 bound to TCP address 0.0.0.0:3000 fd 3
Python version: 3.7.10 (default, Jun 23 2021, 15:44:41)  [GCC 8.3.0]
Python main interpreter initialized at 0x563f3f3d92f0
python threads support enabled
your server socket listen backlog is limited to 100 connections
your mercy for graceful operations on workers is 60 seconds
mapped 218712 bytes (213 KB) for 2 cores
*** Operational MODE: preforking ***
{"severity": "DEBUG", "message": "Falling back to TensorFlow client; we recommended you install the Cloud TPU client directly with pip install cloud-tpu-client.", "request": null, "logger": "tensorflow", "module": "tpu_cluster_resolver", "traceback": "Traceback (most recent call last):\n  File \"/usr/local/lib/python3.7/site-packages/tensorflow/python/distribute/cluster_resolver/tpu/tpu_cluster_resolver.py\", line 33, in <module>\n    from cloud_tpu_client import client  # pylint: disable=g-import-not-at-top\nModuleNotFoundError: No module named 'cloud_tpu_client'\n", "build_version": "dev"}
{"severity": "DEBUG", "message": "Creating converter from %s to %s", "request": null, "logger": "h5py._conv", "module": "__init__", "traceback": null, "build_version": "dev"}
{"severity": "DEBUG", "message": "Creating converter from %s to %s", "request": null, "logger": "h5py._conv", "module": "__init__", "traceback": null, "build_version": "dev"}
{"severity": "DEBUG", "message": "Creating converter from %s to %s", "request": null, "logger": "h5py._conv", "module": "__init__", "traceback": null, "build_version": "dev"}
{"severity": "DEBUG", "message": "Creating converter from %s to %s", "request": null, "logger": "h5py._conv", "module": "__init__", "traceback": null, "build_version": "dev"}
{"severity": "INFO", "message": "{'BUILD_VERSION': 'dev', 'CALCULATION_PLUGIN': 'facenet.Calculator', 'EXTRA_PLUGINS': ['facenet.LandmarksDetector', 'agegender.AgeDetector', 'agegender.GenderDetector', 'facenet.facemask.MaskDetector'], 'FACE_DETECTION_PLUGIN': 'facenet.FaceDetector', 'GPU_IDX': -1, 'IMG_LENGTH_LIMIT': 640, 'INTEL_OPTIMIZATION': False, 'IS_DEV_ENV': False, 'LOGGING_LEVEL_NAME': 'DEBUG', 'ML_PORT': 3000}", "request": null, "logger": "src.app", "module": "app", "traceback": null, "build_version": "dev"}
{"severity": "DEBUG", "message": "Creating new app for WSGI", "request": null, "logger": "src.app", "module": "app", "traceback": null, "build_version": "dev"}
WSGI app 0 (mountpoint='') ready in 14 seconds on interpreter 0x563f3f3d92f0 pid: 1 (default app)
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI master process (pid: 1)
spawned uWSGI worker 1 (pid: 12, cores: 1)
spawned uWSGI worker 2 (pid: 13, cores: 1)

from compreface.

pospielov commented on May 22, 2024

looks like everything ok with compreface-core
Could you run docker ps and show the results?

from compreface.

mcpowell87 commented on May 22, 2024

I am having the same issue. I get 502s when trying to register a new user as well. Running via the latest docker on Debian 11.
compreface-core logs:

[uWSGI] getting INI configuration from uwsgi.ini
*** Starting uWSGI 2.0.19 (64bit) on [Fri Dec 24 07:23:38 2021] ***
compiled with version: 10.2.1 20210110 on 20 October 2021 09:21:55
os: Linux-5.10.0-10-amd64 #1 SMP Debian 5.10.84-1 (2021-12-08)
nodename: b867085fcc8c
machine: x86_64
clock source: unix
detected number of CPU cores: 4
current working directory: /app/ml
detected binary path: /usr/local/bin/uwsgi
!!! no internal routing support, rebuild with pcre support !!!
setgid() to 33
setuid() to 33
your memory page size is 4096 bytes
detected max file descriptor number: 1048576
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uwsgi socket 0 bound to TCP address 0.0.0.0:3000 fd 3
Python version: 3.7.12 (default, Sep 28 2021, 19:53:04)  [GCC 10.2.1 20210110]
Python main interpreter initialized at 0x55fca9875390
python threads support enabled
your server socket listen backlog is limited to 100 connections
your mercy for graceful operations on workers is 60 seconds
mapped 218712 bytes (213 KB) for 2 cores
*** Operational MODE: preforking ***
{"severity": "INFO", "message": "{'BUILD_VERSION': 'dev', 'CALCULATION_PLUGIN': 'facenet.Calculator', 'EXTRA_PLUGINS': ['facenet.LandmarksDetector', 'agegender.AgeDetector', 'agegender.GenderDetector', 'facenet.facemask.MaskDetector'], 'FACE_DETECTION_PLUGIN': 'facenet.FaceDetector', 'GPU_IDX': -1, 'IMG_LENGTH_LIMIT': 640, 'INTEL_OPTIMIZATION': False, 'IS_DEV_ENV': False, 'LOGGING_LEVEL_NAME': 'DEBUG', 'ML_PORT': 3000}", "request": null, "logger": "src.app", "module": "app", "traceback": null, "build_version": "dev"}
{"severity": "DEBUG", "message": "Creating new app for WSGI", "request": null, "logger": "src.app", "module": "app", "traceback": null, "build_version": "dev"}
WSGI app 0 (mountpoint='') ready in 2 seconds on interpreter 0x55fca9875390 pid: 1 (default app)
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI master process (pid: 1)
spawned uWSGI worker 1 (pid: 15, cores: 1)
spawned uWSGI worker 2 (pid: 16, cores: 1)
SIGINT/SIGQUIT received...killing workers...
worker 1 buried after 1 seconds
worker 2 buried after 1 seconds
goodbye to uWSGI.
[uWSGI] getting INI configuration from uwsgi.ini
*** Starting uWSGI 2.0.19 (64bit) on [Fri Dec 24 07:25:14 2021] ***
compiled with version: 10.2.1 20210110 on 20 October 2021 09:21:55
os: Linux-5.10.0-10-amd64 #1 SMP Debian 5.10.84-1 (2021-12-08)
nodename: b867085fcc8c
machine: x86_64
clock source: unix
detected number of CPU cores: 4
current working directory: /app/ml
detected binary path: /usr/local/bin/uwsgi
!!! no internal routing support, rebuild with pcre support !!!
setgid() to 33
setuid() to 33
your memory page size is 4096 bytes
detected max file descriptor number: 1048576
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uwsgi socket 0 bound to TCP address 0.0.0.0:3000 fd 3
Python version: 3.7.12 (default, Sep 28 2021, 19:53:04)  [GCC 10.2.1 20210110]
Python main interpreter initialized at 0x56297b680390
python threads support enabled
your server socket listen backlog is limited to 100 connections
your mercy for graceful operations on workers is 60 seconds
mapped 218712 bytes (213 KB) for 2 cores
*** Operational MODE: preforking ***
{"severity": "INFO", "message": "{'BUILD_VERSION': 'dev', 'CALCULATION_PLUGIN': 'facenet.Calculator', 'EXTRA_PLUGINS': ['facenet.LandmarksDetector', 'agegender.AgeDetector', 'agegender.GenderDetector', 'facenet.facemask.MaskDetector'], 'FACE_DETECTION_PLUGIN': 'facenet.FaceDetector', 'GPU_IDX': -1, 'IMG_LENGTH_LIMIT': 640, 'INTEL_OPTIMIZATION': False, 'IS_DEV_ENV': False, 'LOGGING_LEVEL_NAME': 'DEBUG', 'ML_PORT': 3000}", "request": null, "logger": "src.app", "module": "app", "traceback": null, "build_version": "dev"}
{"severity": "DEBUG", "message": "Creating new app for WSGI", "request": null, "logger": "src.app", "module": "app", "traceback": null, "build_version": "dev"}
WSGI app 0 (mountpoint='') ready in 3 seconds on interpreter 0x56297b680390 pid: 1 (default app)
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI master process (pid: 1)
spawned uWSGI worker 1 (pid: 15, cores: 1)
spawned uWSGI worker 2 (pid: 16, cores: 1)
{"severity": "INFO", "message": "200 OK", "request": {"method": "GET", "path": "/status", "filename": "", "api_key": "", "remote_addr": "172.19.0.5"}, "logger": "src.services.flask_.log_response", "module": "log_response", "traceback": null, "build_version": "dev"}
{"severity": "INFO", "message": "200 OK", "request": {"method": "GET", "path": "/status", "filename": "", "api_key": "", "remote_addr": "172.19.0.5"}, "logger": "src.services.flask_.log_response", "module": "log_response", "traceback": null, "build_version": "dev"}

Docker ps:

CONTAINER ID   IMAGE                                  COMMAND                  CREATED          STATUS          PORTS                                                                                  NAMES
3785370a9b12   exadel/compreface-admin:0.6.1          "sh -c 'java $ADMIN_…"   9 minutes ago    Up 2 minutes                                                                                           compreface-admin
27598fc7e768   exadel/compreface-fe:0.6.1             "/docker-entrypoint.…"   35 minutes ago   Up 34 minutes   0.0.0.0:8000->80/tcp, :::8000->80/tcp                                                  compreface-ui
d0b815d0baa4   exadel/compreface-api:0.6.1            "sh -c 'java $API_JA…"   36 minutes ago   Up 34 minutes                                                                                          compreface-api
3a6150d95765   blakeblackshear/frigate:stable-amd64   "/init python3 -u -m…"   36 minutes ago   Up 18 seconds   0.0.0.0:1935->1935/tcp, :::1935->1935/tcp, 0.0.0.0:5000->5000/tcp, :::5000->5000/tcp   frigate-nvr
b867085fcc8c   exadel/compreface-core:0.6.1           "uwsgi --ini uwsgi.i…"   36 minutes ago   Up 34 minutes   3000/tcp                                                                               compreface-core
f7f3e84688e6   jakowenko/double-take                  "/bin/bash ./entrypo…"   36 minutes ago   Up 34 minutes   0.0.0.0:3001->3000/tcp, :::3001->3000/tcp                                              double-take

from compreface.

pospielov commented on May 22, 2024

I don't see compreface-postgres-db container. Have you set up an external DB?

from compreface.

mcpowell87 commented on May 22, 2024

I don't see compreface-postgres-db container. Have you set up an external DB?

Apologies I forgot to mention that. Yes, I'm using a Postgres 13.5 docker instance I have on another machine. I do see the frs db and various tables created, so I believe connectivity worked.

from compreface.

pospielov commented on May 22, 2024

Could you show your compreface-admin logs?

from compreface.

mcpowell87 commented on May 22, 2024

I do seem to be getting some errors here:

Listening for transport dt_socket at address: 5005
2021-12-27 17:48:04.394  INFO 7 --- [kground-preinit] o.h.validator.internal.util.Version      : HV000001: Hibernate Validator 6.1.5.Final

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.3.4.RELEASE)

2021-12-27 17:48:05.282  INFO 7 --- [           main] com.exadel.frs.FrsApplication            : The following profiles are active: dev
2021-12-27 17:48:07.875  INFO 7 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFERRED mode.
2021-12-27 17:48:08.223  INFO 7 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 331ms. Found 10 JPA repository interfaces.
2021-12-27 17:48:08.718  INFO 7 --- [           main] o.s.cloud.context.scope.GenericScope     : BeanFactory id=e7f41a96-3f70-3efd-b7dc-40aa4699bf29
2021-12-27 17:48:08.901  INFO 7 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'com.exadel.frs.commonservice.system.feign.ApperyStatisticsClient' of type [org.springframework.cloud.openfeign.FeignClientFactoryBean] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2021-12-27 17:48:10.031  INFO 7 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2021-12-27 17:48:10.048  INFO 7 --- [           main] o.a.coyote.http11.Http11NioProtocol      : Initializing ProtocolHandler ["http-nio-8080"]
2021-12-27 17:48:10.049  INFO 7 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2021-12-27 17:48:10.050  INFO 7 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.38]
2021-12-27 17:48:10.158  INFO 7 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2021-12-27 17:48:10.158  INFO 7 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 4829 ms
2021-12-27 17:48:10.813  INFO 7 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2021-12-27 17:48:11.066  INFO 7 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
2021-12-27 17:48:11.881  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:48:21.886  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:48:31.891  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:48:41.896  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:48:51.900  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:49:01.905  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:49:11.909  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:49:21.913  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:49:31.917  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:49:41.921  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:49:51.925  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:50:01.929  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:50:11.933  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:50:21.939  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:50:31.944  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:50:41.949  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:50:51.959  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:51:01.963  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:51:11.967  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:51:21.971  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:51:31.975  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:51:41.979  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:51:51.984  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:52:01.988  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:52:11.993  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:52:21.997  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:52:32.004  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:52:42.007  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:52:52.012  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:53:02.016  INFO 7 --- [           main] liquibase.lockservice                    : Waiting for changelog lock....
2021-12-27 17:53:12.024  WARN 7 --- [           main] ConfigServletWebServerApplicationContext : Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'liquibase' defined in class path resource [org/springframework/boot/autoconfigure/liquibase/LiquibaseAutoConfiguration$LiquibaseConfiguration.class]: Invocation of init method failed; nested exception is liquibase.exception.LockException: Could not acquire change log lock.  Currently locked by d0c479c69a60 (172.18.0.6) since 12/24/21, 6:41 AM
2021-12-27 17:53:12.024  INFO 7 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown initiated...
2021-12-27 17:53:12.031  INFO 7 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown completed.
2021-12-27 17:53:12.034  INFO 7 --- [           main] o.apache.catalina.core.StandardService   : Stopping service [Tomcat]
2021-12-27 17:53:12.063  INFO 7 --- [           main] ConditionEvaluationReportLoggingListener :

Error starting ApplicationContext. To display the conditions report re-run your application with 'debug' enabled.
2021-12-27 17:53:12.070 ERROR 7 --- [           main] o.s.boot.SpringApplication               : Application run failed

org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'liquibase' defined in class path resource [org/springframework/boot/autoconfigure/liquibase/LiquibaseAutoConfiguration$LiquibaseConfiguration.class]: Invocation of init method failed; nested exception is liquibase.exception.LockException: Could not acquire change log lock.  Currently locked by d0c479c69a60 (172.18.0.6) since 12/24/21, 6:41 AM
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1794)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:594)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:516)
        at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:324)
        at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234)
        at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:322)
        at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
        at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:311)
        at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
        at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:1109)
        at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:869)
        at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:551)
        at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:143)
        at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:758)
        at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:750)
        at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:397)
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:315)
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1237)
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1226)
        at com.exadel.frs.FrsApplication.main(FrsApplication.java:28)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
        at java.base/java.lang.reflect.Method.invoke(Unknown Source)
        at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:49)
        at org.springframework.boot.loader.Launcher.launch(Launcher.java:107)
        at org.springframework.boot.loader.Launcher.launch(Launcher.java:58)
        at org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:88)
Caused by: liquibase.exception.LockException: Could not acquire change log lock.  Currently locked by d0c479c69a60 (172.18.0.6) since 12/24/21, 6:41 AM
        at liquibase.lockservice.StandardLockService.waitForLock(StandardLockService.java:235)
        at liquibase.Liquibase.lambda$update$1(Liquibase.java:220)
        at liquibase.Scope.lambda$child$0(Scope.java:160)
        at liquibase.Scope.child(Scope.java:169)
        at liquibase.Scope.child(Scope.java:159)
        at liquibase.Scope.child(Scope.java:138)
        at liquibase.Liquibase.runInScope(Liquibase.java:2369)
        at liquibase.Liquibase.update(Liquibase.java:217)
        at liquibase.Liquibase.update(Liquibase.java:203)
        at liquibase.integration.spring.SpringLiquibase.performUpdate(SpringLiquibase.java:321)
        at liquibase.integration.spring.SpringLiquibase.afterPropertiesSet(SpringLiquibase.java:275)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1853)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1790)
        ... 27 common frames omitted

from compreface.

pospielov commented on May 22, 2024

This is the error.
Liquibase that initializes the database tries to acquire lock but fails. It happens sometimes if you started the system and before all initialization is done, it stops.
The solution here is just to clear the database, so it will initiate it again.
Just wait enough time until it's done, it usually it takes about 30 seconds

from compreface.

mcpowell87 commented on May 22, 2024

Indeed that was the issue. Thank you!

from compreface.

elvato87 commented on May 22, 2024

Hello, I'm getting the same 502 error code, but it's not the liquidbase for me, I hope you can Help me, I'm Using Version 0.6.1 and running on Windows on Docker Desktop V 4.3.2

I'm using the API using postman, but if i try to load an image in the web interface the same error apperars

This is the code for the request

curl --location --request POST 'http://localhost:8000/api/v1/recognition/faces?subject=633875' \
--header 'x-api-key: 41cbae47-d62d-4071-b5eb-df51b681899c' \
--form 'file=@"/C:/Pictures/W1100000637487264272374895.jpg"'

Docker PS

CONTAINER ID   IMAGE                           COMMAND                  CREATED        STATUS          PORTS                  NAMES
b0dd734816bd   exadel/compreface-fe:0.6.1      "/docker-entrypoint.…"   15 hours ago   Up 25 minutes   0.0.0.0:8000->80/tcp   compreface-ui
2f2a02161410   exadel/compreface-admin:0.6.1   "sh -c 'java $ADMIN_…"   15 hours ago   Up 25 minutes                          compreface-admin
515ffa7239c1   exadel/compreface-api:0.6.1     "sh -c 'java $API_JA…"   15 hours ago   Up 2 minutes                           compreface-api
58df83a969df   postgres:11.5                   "docker-entrypoint.s…"   15 hours ago   Up 25 minutes   5432/tcp               compreface-postgres-db
f24d93237d5a   exadel/compreface-core:0.6.1    "uwsgi --ini uwsgi.i…"   15 hours ago   Up 25 minutes   3000/tcp               compreface-core

docker logs compreface-core

[uWSGI] getting INI configuration from uwsgi.ini
*** Starting uWSGI 2.0.19 (64bit) on [Fri Jan  7 23:40:54 2022] ***
compiled with version: 10.2.1 20210110 on 20 October 2021 09:21:55
os: Linux-5.10.16.3-microsoft-standard-WSL2 #1 SMP Fri Apr 2 22:23:49 UTC 2021
nodename: f24d93237d5a
machine: x86_64
clock source: unix
detected number of CPU cores: 2
current working directory: /app/ml
detected binary path: /usr/local/bin/uwsgi
!!! no internal routing support, rebuild with pcre support !!!
setgid() to 33
setuid() to 33
your memory page size is 4096 bytes
detected max file descriptor number: 1048576
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uwsgi socket 0 bound to TCP address 0.0.0.0:3000 fd 3
Python version: 3.7.12 (default, Sep 28 2021, 19:53:04)  [GCC 10.2.1 20210110]
Python main interpreter initialized at 0x5650ada38380
python threads support enabled
your server socket listen backlog is limited to 100 connections
your mercy for graceful operations on workers is 60 seconds
mapped 218712 bytes (213 KB) for 2 cores
*** Operational MODE: preforking ***
{"severity": "INFO", "message": "{'BUILD_VERSION': 'dev', 'CALCULATION_PLUGIN': 'facenet.Calculator', 'EXTRA_PLUGINS': ['facenet.LandmarksDetector', 'agegender.AgeDetector', 'agegender.GenderDetector', 'facenet.facemask.MaskDetector'], 'FACE_DETECTION_PLUGIN': 'facenet.FaceDetector', 'GPU_IDX': -1, 'IMG_LENGTH_LIMIT': 640, 'INTEL_OPTIMIZATION': False, 'IS_DEV_ENV': False, 'LOGGING_LEVEL_NAME': 'DEBUG', 'ML_PORT': 3000}", "request": null, "logger": "src.app", "module": "app", "traceback": null, "build_version": "dev"}
{"severity": "DEBUG", "message": "Creating new app for WSGI", "request": null, "logger": "src.app", "module": "app", "traceback": null, "build_version": "dev"}
WSGI app 0 (mountpoint='') ready in 9 seconds on interpreter 0x5650ada38380 pid: 1 (default app)
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI master process (pid: 1)
spawned uWSGI worker 1 (pid: 12, cores: 1)
spawned uWSGI worker 2 (pid: 13, cores: 1)
{"severity": "INFO", "message": "200 OK", "request": {"method": "GET", "path": "/status", "filename": "", "api_key": "", "remote_addr": "172.19.0.4"}, "logger": "src.services.flask_.log_response", "module": "log_response", "traceback": null, "build_version": "dev"}
2022-01-07 23:50:43.470229: E tensorflow/stream_executor/cuda/cuda_driver.cc:351] failed call to cuInit: UNKNOWN ERROR (303)
{"severity": "DEBUG", "message": "Found: BoundingBoxDTO(x_min=115, y_min=35, x_max=337, y_max=297, probability=0.9962306618690491, _np_landmarks=array([[187, 146],\n       [259, 145],\n       [222, 192],\n       [194, 227],\n       [255, 227]]))", "request": {"method": "POST", "path": "/find_faces", "filename": "W1100000637487264272374895.jpg", "api_key": "", "remote_addr": "172.19.0.4"}, "logger": "src.services.facescan.plugins.facenet.facenet", "module": "facenet", "traceback": null, "build_version": "dev"}
DAMN ! worker 1 (pid: 12) died, killed by signal 9 :( trying respawn ...
Respawned uWSGI worker 1 (new pid: 83)
2022-01-07 23:52:06.428057: E tensorflow/stream_executor/cuda/cuda_driver.cc:351] failed call to cuInit: UNKNOWN ERROR (303)
{"severity": "DEBUG", "message": "Found: BoundingBoxDTO(x_min=80, y_min=59, x_max=422, y_max=455, probability=0.9968720078468323, _np_landmarks=array([[202, 218],\n       [312, 219],\n       [264, 280],\n       [209, 341],\n       [306, 339]]))", "request": {"method": "POST", "path": "/find_faces", "filename": "Antonio_P_002.jpeg", "api_key": "", "remote_addr": "172.19.0.4"}, "logger": "src.services.facescan.plugins.facenet.facenet", "module": "facenet", "traceback": null, "build_version": "dev"}
DAMN ! worker 2 (pid: 13) died, killed by signal 9 :( trying respawn ...
Respawned uWSGI worker 2 (new pid: 154)
[uWSGI] getting INI configuration from uwsgi.ini
*** Starting uWSGI 2.0.19 (64bit) on [Sat Jan  8 14:00:27 2022] ***
compiled with version: 10.2.1 20210110 on 20 October 2021 09:21:55
os: Linux-5.10.16.3-microsoft-standard-WSL2 #1 SMP Fri Apr 2 22:23:49 UTC 2021
nodename: f24d93237d5a
machine: x86_64
clock source: unix
detected number of CPU cores: 2
current working directory: /app/ml
detected binary path: /usr/local/bin/uwsgi
!!! no internal routing support, rebuild with pcre support !!!
setgid() to 33
setuid() to 33
your memory page size is 4096 bytes
detected max file descriptor number: 1048576
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uwsgi socket 0 bound to TCP address 0.0.0.0:3000 fd 3
Python version: 3.7.12 (default, Sep 28 2021, 19:53:04)  [GCC 10.2.1 20210110]
Python main interpreter initialized at 0x55fed7ea3380
python threads support enabled
your server socket listen backlog is limited to 100 connections
your mercy for graceful operations on workers is 60 seconds
mapped 218712 bytes (213 KB) for 2 cores
*** Operational MODE: preforking ***
{"severity": "INFO", "message": "{'BUILD_VERSION': 'dev', 'CALCULATION_PLUGIN': 'facenet.Calculator', 'EXTRA_PLUGINS': ['facenet.LandmarksDetector', 'agegender.AgeDetector', 'agegender.GenderDetector', 'facenet.facemask.MaskDetector'], 'FACE_DETECTION_PLUGIN': 'facenet.FaceDetector', 'GPU_IDX': -1, 'IMG_LENGTH_LIMIT': 640, 'INTEL_OPTIMIZATION': False, 'IS_DEV_ENV': False, 'LOGGING_LEVEL_NAME': 'DEBUG', 'ML_PORT': 3000}", "request": null, "logger": "src.app", "module": "app", "traceback": null, "build_version": "dev"}
{"severity": "DEBUG", "message": "Creating new app for WSGI", "request": null, "logger": "src.app", "module": "app", "traceback": null, "build_version": "dev"}
WSGI app 0 (mountpoint='') ready in 16 seconds on interpreter 0x55fed7ea3380 pid: 1 (default app)
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI master process (pid: 1)
spawned uWSGI worker 1 (pid: 12, cores: 1)
spawned uWSGI worker 2 (pid: 13, cores: 1)
2022-01-08 14:22:11.799434: E tensorflow/stream_executor/cuda/cuda_driver.cc:351] failed call to cuInit: UNKNOWN ERROR (303)
{"severity": "DEBUG", "message": "Found: BoundingBoxDTO(x_min=115, y_min=35, x_max=337, y_max=297, probability=0.9962306618690491, _np_landmarks=array([[187, 146],\n       [259, 145],\n       [222, 192],\n       [194, 227],\n       [255, 227]]))", "request": {"method": "POST", "path": "/find_faces", "filename": "W1100000637487264272374895.jpg", "api_key": "", "remote_addr": "172.19.0.6"}, "logger": "src.services.facescan.plugins.facenet.facenet", "module": "facenet", "traceback": null, "build_version": "dev"}
DAMN ! worker 1 (pid: 12) died, killed by signal 9 :( trying respawn ...
Respawned uWSGI worker 1 (new pid: 83)
{"severity": "INFO", "message": "200 OK", "request": {"method": "GET", "path": "/status", "filename": "", "api_key": "", "remote_addr": "172.19.0.6"}, "logger": "src.services.flask_.log_response", "module": "log_response", "traceback": null, "build_version": "dev"}

What I see there is this error tensorflow/stream_executor/cuda/cuda_driver.cc:351] failed call to cuInit: UNKNOWN ERROR (303)

docker logs compreface-admin

Listening for transport dt_socket at address: 5005
2022-01-07 23:41:08.440  INFO 7 --- [kground-preinit] o.h.validator.internal.util.Version      : HV000001: Hibernate Validator 6.1.5.Final

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.3.4.RELEASE)

2022-01-07 23:41:11.893  INFO 7 --- [           main] com.exadel.frs.FrsApplication            : The following profiles are active: dev
2022-01-07 23:41:19.796  INFO 7 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFERRED mode.
2022-01-07 23:41:20.742  INFO 7 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 859ms. Found 10 JPA repository interfaces.
2022-01-07 23:41:22.465  INFO 7 --- [           main] o.s.cloud.context.scope.GenericScope     : BeanFactory id=e7f41a96-3f70-3efd-b7dc-40aa4699bf29
2022-01-07 23:41:23.191  INFO 7 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'com.exadel.frs.commonservice.system.feign.ApperyStatisticsClient' of type [org.springframework.cloud.openfeign.FeignClientFactoryBean] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2022-01-07 23:41:26.598  INFO 7 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2022-01-07 23:41:26.657  INFO 7 --- [           main] o.a.coyote.http11.Http11NioProtocol      : Initializing ProtocolHandler ["http-nio-8080"]
2022-01-07 23:41:26.658  INFO 7 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2022-01-07 23:41:26.658  INFO 7 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.38]
2022-01-07 23:41:27.301  INFO 7 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2022-01-07 23:41:27.302  INFO 7 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 15215 ms
2022-01-07 23:41:29.168  INFO 7 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2022-01-07 23:41:29.940  INFO 7 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
2022-01-07 23:41:32.518  INFO 7 --- [           main] liquibase.lockservice                    : Successfully acquired change log lock
2022-01-07 23:41:35.165  INFO 7 --- [           main] liquibase.changelog                      : Reading from public.databasechangelog
2022-01-07 23:41:35.970  INFO 7 --- [           main] liquibase.lockservice                    : Successfully released change log lock
2022-01-07 23:41:35.999  INFO 7 --- [           main] liquibase.lockservice                    : Successfully acquired change log lock
Skipping auto-registration
2022-01-07 23:41:36.026  WARN 7 --- [           main] liquibase.hub                            : Skipping auto-registration
2022-01-07 23:41:36.078  INFO 7 --- [           main] liquibase.lockservice                    : Successfully released change log lock
2022-01-07 23:41:36.794  INFO 7 --- [           main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2022-01-07 23:41:36.834  INFO 7 --- [           main] o.s.s.c.ThreadPoolTaskScheduler          : Initializing ExecutorService 'taskScheduler'
2022-01-07 23:41:37.411  INFO 7 --- [         task-1] o.hibernate.jpa.internal.util.LogHelper  : HHH000204: Processing PersistenceUnitInfo [name: default]
2022-01-07 23:41:38.292  INFO 7 --- [         task-1] org.hibernate.Version                    : HHH000412: Hibernate ORM core version 5.4.21.Final
2022-01-07 23:41:40.011  INFO 7 --- [         task-1] o.hibernate.annotations.common.Version   : HCANN000001: Hibernate Commons Annotations {5.1.0.Final}
2022-01-07 23:41:41.350  INFO 7 --- [         task-1] org.hibernate.dialect.Dialect            : HHH000400: Using dialect: org.hibernate.dialect.PostgreSQL10Dialect
2022-01-07 23:41:44.274  WARN 7 --- [         task-1] Hibernate Types                          : You should use Hypersistence Optimizer to speed up your Hibernate application!
2022-01-07 23:41:44.283  WARN 7 --- [         task-1] Hibernate Types                          : For more details, go to https://vladmihalcea.com/hypersistence-optimizer/
2022-01-07 23:41:44.286  INFO 7 --- [         task-1] Hibernate Types                          :
 _    _                           _     _
| |  | |                         (_)   | |
| |__| |_   _ _ __   ___ _ __ ___ _ ___| |_ ___ _ __   ___ ___
|  __  | | | | '_ \ / _ \ '__/ __| / __| __/ _ \ '_ \ / __/ _ \
| |  | | |_| | |_) |  __/ |  \__ \ \__ \ ||  __/ | | | (_|  __/
|_|  |_|\__, | .__/ \___|_|  |___/_|___/\__\___|_| |_|\___\___|
         __/ | |
        |___/|_|

           ____        _   _           _
          / __ \      | | (_)         (_)
         | |  | |_ __ | |_ _ _ __ ___  _ _______ _ __
         | |  | | '_ \| __| | '_ ` _ \| |_  / _ \ '__|
         | |__| | |_) | |_| | | | | | | |/ /  __/ |
          \____/| .__/ \__|_|_| |_| |_|_/___\___|_|
                | |
                |_|

2022-01-07 23:41:44.288  INFO 7 --- [         task-1] Hibernate Types                          : Check out the README page for more info about the Hypersistence Optimizer banner https://github.com/vladmihalcea/hibernate-types#how-to-remove-the-hypersistence-optimizer-banner-from-the-log
2022-01-07 23:41:44.320  INFO 7 --- [           main] DeferredRepositoryInitializationListener : Triggering deferred initialization of Spring Data repositories…
2022-01-07 23:41:48.976  INFO 7 --- [         task-1] o.h.e.t.j.p.i.JtaPlatformInitiator       : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2022-01-07 23:41:48.998  INFO 7 --- [         task-1] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
2022-01-07 23:41:54.333  INFO 7 --- [           main] DeferredRepositoryInitializationListener : Spring Data repositories initialized!
2022-01-07 23:41:57.610  INFO 7 --- [           main] o.s.b.a.e.web.EndpointLinksResolver      : Exposing 2 endpoint(s) beneath base path '/actuator'
2022-01-07 23:41:58.476  INFO 7 --- [           main] pertySourcedRequestMappingHandlerMapping : Mapped URL path [/v2/api-docs] onto method [springfox.documentation.swagger2.web.Swagger2Controller#getDocumentation(String, HttpServletRequest)]
2022-01-07 23:42:01.914  INFO 7 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Creating filter chain: Ant [pattern='/v2/api-docs'], []
2022-01-07 23:42:01.915  INFO 7 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Creating filter chain: Ant [pattern='/configuration/ui'], []
2022-01-07 23:42:01.916  INFO 7 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Creating filter chain: Ant [pattern='/swagger-resources/**'], []
2022-01-07 23:42:01.916  INFO 7 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Creating filter chain: Ant [pattern='/configuration/**'], []
2022-01-07 23:42:01.916  INFO 7 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Creating filter chain: Ant [pattern='/swagger-ui**'], []
2022-01-07 23:42:01.918  INFO 7 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Creating filter chain: Ant [pattern='/webjars/**'], []
2022-01-07 23:42:01.919  INFO 7 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Creating filter chain: Ant [pattern='/lms/**'], []
2022-01-07 23:42:02.202  INFO 7 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Creating filter chain: OrRequestMatcher [requestMatchers=[Ant [pattern='/oauth/token'], Ant [pattern='/oauth/token_key'], Ant [pattern='/oauth/check_token']]], [org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter@414e8b31, org.springframework.security.web.context.SecurityContextPersistenceFilter@20155dae, org.springframework.security.web.header.HeaderWriterFilter@205f52ea, org.springframework.security.web.authentication.logout.LogoutFilter@416d90f0, org.springframework.security.web.authentication.www.BasicAuthenticationFilter@14d1032a, org.springframework.security.web.savedrequest.RequestCacheAwareFilter@6c49ea0c, org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter@2a4cb8ae, org.springframework.security.web.authentication.AnonymousAuthenticationFilter@b90c5a5, org.springframework.security.web.session.SessionManagementFilter@24b8a393, org.springframework.security.web.access.ExceptionTranslationFilter@73a116d, org.springframework.security.web.access.intercept.FilterSecurityInterceptor@6df31abf]
2022-01-07 23:42:02.270  INFO 7 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Creating filter chain: org.springframework.security.oauth2.config.annotation.web.configuration.ResourceServerConfiguration$NotOAuthRequestMatcher@7fd3fd06, [org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter@54ae1240, org.springframework.security.web.context.SecurityContextPersistenceFilter@53d808ea, org.springframework.security.web.header.HeaderWriterFilter@4e3ffd0, org.springframework.security.web.authentication.logout.LogoutFilter@5383bf08, org.springframework.security.oauth2.provider.authentication.OAuth2AuthenticationProcessingFilter@2e4339c1, org.springframework.security.web.savedrequest.RequestCacheAwareFilter@44864ebe, org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter@5f803481, org.springframework.security.web.authentication.AnonymousAuthenticationFilter@1c2b65cc, org.springframework.security.web.session.SessionManagementFilter@5ca86715, org.springframework.security.web.access.ExceptionTranslationFilter@3164d5aa, org.springframework.security.web.access.intercept.FilterSecurityInterceptor@5ebf776c]
2022-01-07 23:42:02.287  INFO 7 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Creating filter chain: any request, [org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter@b529d7e, org.springframework.security.web.context.SecurityContextPersistenceFilter@16a499d1, org.springframework.security.web.header.HeaderWriterFilter@520ee6b3, org.springframework.security.web.authentication.logout.LogoutFilter@84a9f65, org.springframework.security.web.savedrequest.RequestCacheAwareFilter@2bf4fa1, org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter@27210a3b, org.springframework.security.web.authentication.AnonymousAuthenticationFilter@3664c596, org.springframework.security.web.session.SessionManagementFilter@15f11bfb, org.springframework.security.web.access.ExceptionTranslationFilter@3514237f, org.springframework.security.web.access.intercept.FilterSecurityInterceptor@523ade68]
2022-01-07 23:42:04.082  INFO 7 --- [           main] org.quartz.impl.StdSchedulerFactory      : Using default implementation for ThreadExecutor
2022-01-07 23:42:04.138  INFO 7 --- [           main] org.quartz.core.SchedulerSignalerImpl    : Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
2022-01-07 23:42:04.138  INFO 7 --- [           main] org.quartz.core.QuartzScheduler          : Quartz Scheduler v.2.3.2 created.
2022-01-07 23:42:04.151  INFO 7 --- [           main] o.s.s.quartz.LocalDataSourceJobStore     : Using db table-based data access locking (synchronization).
2022-01-07 23:42:04.167  INFO 7 --- [           main] o.s.s.quartz.LocalDataSourceJobStore     : JobStoreCMT initialized.
2022-01-07 23:42:04.170  INFO 7 --- [           main] org.quartz.core.QuartzScheduler          : Scheduler meta-data: Quartz Scheduler (v2.3.2) 'statistics scheduler' with instanceId 'NON_CLUSTERED'
  Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally.
  NOT STARTED.
  Currently in standby mode.
  Number of jobs executed: 0
  Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 1 threads.
  Using job-store 'org.springframework.scheduling.quartz.LocalDataSourceJobStore' - which supports persistence. and is not clustered.

2022-01-07 23:42:04.171  INFO 7 --- [           main] org.quartz.impl.StdSchedulerFactory      : Quartz scheduler 'statistics scheduler' initialized from an externally provided properties instance.
2022-01-07 23:42:04.171  INFO 7 --- [           main] org.quartz.impl.StdSchedulerFactory      : Quartz scheduler version: 2.3.2
2022-01-07 23:42:04.171  INFO 7 --- [           main] org.quartz.core.QuartzScheduler          : JobFactory set to: org.springframework.scheduling.quartz.SpringBeanJobFactory@7d70ba18
2022-01-07 23:42:04.442  INFO 7 --- [           main] o.s.s.quartz.LocalDataSourceJobStore     : Freed 0 triggers from 'acquired' / 'blocked' state.
2022-01-07 23:42:04.449  INFO 7 --- [           main] o.s.s.quartz.LocalDataSourceJobStore     : Recovering 0 jobs that were in-progress at the time of the last shut-down.
2022-01-07 23:42:04.451  INFO 7 --- [           main] o.s.s.quartz.LocalDataSourceJobStore     : Recovery complete.
2022-01-07 23:42:04.457  INFO 7 --- [           main] o.s.s.quartz.LocalDataSourceJobStore     : Removed 0 'complete' triggers.
2022-01-07 23:42:04.458  INFO 7 --- [           main] o.s.s.quartz.LocalDataSourceJobStore     : Removed 0 stale fired job entries.
2022-01-07 23:42:04.465  INFO 7 --- [           main] org.quartz.core.QuartzScheduler          : Scheduler statistics scheduler_$_NON_CLUSTERED started.
2022-01-07 23:42:04.622  WARN 7 --- [           main] c.n.c.sources.URLConfigurationSource     : No URLs will be polled as dynamic configuration sources.
2022-01-07 23:42:04.622  INFO 7 --- [           main] c.n.c.sources.URLConfigurationSource     : To enable URLs as dynamic configuration sources, define System property archaius.configurationSource.additionalUrls or make config.properties available on classpath.
2022-01-07 23:42:04.689  WARN 7 --- [           main] c.n.c.sources.URLConfigurationSource     : No URLs will be polled as dynamic configuration sources.
2022-01-07 23:42:04.690  INFO 7 --- [           main] c.n.c.sources.URLConfigurationSource     : To enable URLs as dynamic configuration sources, define System property archaius.configurationSource.additionalUrls or make config.properties available on classpath.
2022-01-07 23:42:08.279  INFO 7 --- [           main] o.a.coyote.http11.Http11NioProtocol      : Starting ProtocolHandler ["http-nio-8080"]
2022-01-07 23:42:08.616  INFO 7 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2022-01-07 23:42:08.621  INFO 7 --- [           main] d.s.w.p.DocumentationPluginsBootstrapper : Context refreshed
2022-01-07 23:42:08.690  INFO 7 --- [           main] d.s.w.p.DocumentationPluginsBootstrapper : Found 1 custom documentation plugin(s)
2022-01-07 23:42:08.831  INFO 7 --- [           main] s.d.s.w.s.ApiListingReferenceScanner     : Scanning for api listing references
2022-01-07 23:42:09.441  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: regenerateApiKeyUsingPUT_1
2022-01-07 23:42:09.573  INFO 7 --- [           main] DeferredRepositoryInitializationListener : Triggering deferred initialization of Spring Data repositories…
2022-01-07 23:42:09.573  INFO 7 --- [           main] DeferredRepositoryInitializationListener : Spring Data repositories initialized!
2022-01-07 23:42:09.656  INFO 7 --- [           main] com.exadel.frs.FrsApplication            : Started FrsApplication in 65.603 seconds (JVM running for 72.156)
2022-01-07 23:42:48.536  INFO 7 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2022-01-07 23:42:48.537  INFO 7 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2022-01-07 23:42:48.588  INFO 7 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 51 ms
2022-01-07 23:45:25.792  WARN 7 --- [nio-8080-exec-5] c.e.f.s.s.endpoint.CustomTokenEndpoint   : Handling error: InvalidGrantException, Bad credentials
2022-01-07 23:46:17.179  INFO 7 --- [nio-8080-exec-8] com.exadel.frs.service.UserService       : Demo user update with userCreateDto: UserCreateDto([email protected], firstName=Salvador, lastName=Cruz, password=ComparaCaras#87, isAllowStatistics=true)
2022-01-07 23:46:17.702  INFO 7 --- [nio-8080-exec-8] c.e.f.c.a.StatisticsCollectionAspect     : Request to send statistics in background
2022-01-07 23:47:35.555  INFO 7 --- [nio-8080-exec-2] o.s.s.o.p.token.store.JdbcTokenStore     : Failed to find access token for token 24df3b88-535c-451b-97e3-e84a46b2e421
2022-01-07 23:47:48.229  INFO 7 --- [nio-8080-exec-6] c.e.f.c.a.StatisticsCollectionAspect     : Request to send statistics in background
2022-01-07 23:48:51.231  INFO 7 --- [nio-8080-exec-9] com.exadel.frs.service.ModelService      : model type: RECOGNITION
2022-01-07 23:48:51.295  INFO 7 --- [nio-8080-exec-9] com.exadel.frs.service.ModelService      : recognition model created: Model(id=1, name=SchoolRecognition, guid=261c387c-f563-4888-a37a-a4d00a79e6f2, apiKey=41cbae47-d62d-4071-b5eb-df51b681899c, type=RECOGNITION, app=App(id=1, name=School, guid=1fe7c737-17d9-44a0-ae11-9e9f66c9c5b6, apiKey=4738c41e-9766-42c4-ab19-a580a00d30fc))
2022-01-07 23:48:51.400  INFO 7 --- [nio-8080-exec-9] c.e.f.c.a.StatisticsCollectionAspect     : Request to send statistics in background
2022-01-07 23:49:01.230  INFO 7 --- [nio-8080-exec-8] com.exadel.frs.service.ModelService      : model type: VERIFY
2022-01-07 23:49:01.258  INFO 7 --- [nio-8080-exec-8] com.exadel.frs.service.ModelService      : verification model created: Model(id=2, name=SchoolVerification, guid=a4d37379-143f-4e48-9f76-53d0c29147be, apiKey=6f78678e-7712-4724-b6f0-9fe8651d5b9e, type=VERIFY, app=App(id=1, name=School, guid=1fe7c737-17d9-44a0-ae11-9e9f66c9c5b6, apiKey=4738c41e-9766-42c4-ab19-a580a00d30fc))
2022-01-07 23:49:01.260  INFO 7 --- [nio-8080-exec-8] c.e.f.c.a.StatisticsCollectionAspect     : Request to send statistics in background
2022-01-07 23:49:10.201  INFO 7 --- [nio-8080-exec-1] com.exadel.frs.service.ModelService      : model type: DETECTION
2022-01-07 23:49:10.237  INFO 7 --- [nio-8080-exec-1] com.exadel.frs.service.ModelService      : detection model created: Model(id=3, name=SchoolDetection, guid=c39adade-8700-49f6-8e0f-5989927836ca, apiKey=e1105eac-5766-4250-bc2e-95b80a604941, type=DETECTION, app=App(id=1, name=School, guid=1fe7c737-17d9-44a0-ae11-9e9f66c9c5b6, apiKey=4738c41e-9766-42c4-ab19-a580a00d30fc))
2022-01-07 23:49:10.238  INFO 7 --- [nio-8080-exec-1] c.e.f.c.a.StatisticsCollectionAspect     : Request to send statistics in background
Listening for transport dt_socket at address: 5005
2022-01-08 14:00:40.183  INFO 8 --- [kground-preinit] o.h.validator.internal.util.Version      : HV000001: Hibernate Validator 6.1.5.Final

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.3.4.RELEASE)

2022-01-08 14:00:43.571  INFO 8 --- [           main] com.exadel.frs.FrsApplication            : The following profiles are active: dev
2022-01-08 14:00:51.849  INFO 8 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFERRED mode.
2022-01-08 14:00:52.835  INFO 8 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 900ms. Found 10 JPA repository interfaces.
2022-01-08 14:00:54.389  INFO 8 --- [           main] o.s.cloud.context.scope.GenericScope     : BeanFactory id=e7f41a96-3f70-3efd-b7dc-40aa4699bf29
2022-01-08 14:00:54.968  INFO 8 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'com.exadel.frs.commonservice.system.feign.ApperyStatisticsClient' of type [org.springframework.cloud.openfeign.FeignClientFactoryBean] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2022-01-08 14:00:58.048  INFO 8 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2022-01-08 14:00:58.099  INFO 8 --- [           main] o.a.coyote.http11.Http11NioProtocol      : Initializing ProtocolHandler ["http-nio-8080"]
2022-01-08 14:00:58.100  INFO 8 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2022-01-08 14:00:58.100  INFO 8 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.38]
2022-01-08 14:00:58.692  INFO 8 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2022-01-08 14:00:58.693  INFO 8 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 14877 ms
2022-01-08 14:01:00.795  INFO 8 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2022-01-08 14:01:01.902  INFO 8 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
2022-01-08 14:01:04.267  INFO 8 --- [           main] liquibase.lockservice                    : Successfully acquired change log lock
2022-01-08 14:01:06.651  INFO 8 --- [           main] liquibase.changelog                      : Reading from public.databasechangelog
2022-01-08 14:01:07.367  INFO 8 --- [           main] liquibase.lockservice                    : Successfully released change log lock
2022-01-08 14:01:07.379  INFO 8 --- [           main] liquibase.lockservice                    : Successfully acquired change log lock
Skipping auto-registration
2022-01-08 14:01:07.411  WARN 8 --- [           main] liquibase.hub                            : Skipping auto-registration
2022-01-08 14:01:07.504  INFO 8 --- [           main] liquibase.lockservice                    : Successfully released change log lock
2022-01-08 14:01:08.290  INFO 8 --- [           main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2022-01-08 14:01:08.376  INFO 8 --- [           main] o.s.s.c.ThreadPoolTaskScheduler          : Initializing ExecutorService 'taskScheduler'
2022-01-08 14:01:09.141  INFO 8 --- [         task-1] o.hibernate.jpa.internal.util.LogHelper  : HHH000204: Processing PersistenceUnitInfo [name: default]
2022-01-08 14:01:16.268  INFO 8 --- [         task-1] org.hibernate.Version                    : HHH000412: Hibernate ORM core version 5.4.21.Final
2022-01-08 14:01:22.327  INFO 8 --- [         task-1] o.hibernate.annotations.common.Version   : HCANN000001: Hibernate Commons Annotations {5.1.0.Final}
2022-01-08 14:01:24.086  INFO 8 --- [         task-1] org.hibernate.dialect.Dialect            : HHH000400: Using dialect: org.hibernate.dialect.PostgreSQL10Dialect
2022-01-08 14:01:26.141  INFO 8 --- [           main] DeferredRepositoryInitializationListener : Triggering deferred initialization of Spring Data repositories…
2022-01-08 14:01:26.926  WARN 8 --- [         task-1] Hibernate Types                          : You should use Hypersistence Optimizer to speed up your Hibernate application!
2022-01-08 14:01:26.927  WARN 8 --- [         task-1] Hibernate Types                          : For more details, go to https://vladmihalcea.com/hypersistence-optimizer/
2022-01-08 14:01:26.927  INFO 8 --- [         task-1] Hibernate Types                          :
 _    _                           _     _
| |  | |                         (_)   | |
| |__| |_   _ _ __   ___ _ __ ___ _ ___| |_ ___ _ __   ___ ___
|  __  | | | | '_ \ / _ \ '__/ __| / __| __/ _ \ '_ \ / __/ _ \
| |  | | |_| | |_) |  __/ |  \__ \ \__ \ ||  __/ | | | (_|  __/
|_|  |_|\__, | .__/ \___|_|  |___/_|___/\__\___|_| |_|\___\___|
         __/ | |
        |___/|_|

           ____        _   _           _
          / __ \      | | (_)         (_)
         | |  | |_ __ | |_ _ _ __ ___  _ _______ _ __
         | |  | | '_ \| __| | '_ ` _ \| |_  / _ \ '__|
         | |__| | |_) | |_| | | | | | | |/ /  __/ |
          \____/| .__/ \__|_|_| |_| |_|_/___\___|_|
                | |
                |_|

2022-01-08 14:01:26.928  INFO 8 --- [         task-1] Hibernate Types                          : Check out the README page for more info about the Hypersistence Optimizer banner https://github.com/vladmihalcea/hibernate-types#how-to-remove-the-hypersistence-optimizer-banner-from-the-log
2022-01-08 14:01:31.376  INFO 8 --- [         task-1] o.h.e.t.j.p.i.JtaPlatformInitiator       : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2022-01-08 14:01:31.403  INFO 8 --- [         task-1] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
2022-01-08 14:01:38.333  INFO 8 --- [           main] DeferredRepositoryInitializationListener : Spring Data repositories initialized!
2022-01-08 14:01:44.491  INFO 8 --- [           main] o.s.b.a.e.web.EndpointLinksResolver      : Exposing 2 endpoint(s) beneath base path '/actuator'
2022-01-08 14:01:46.532  INFO 8 --- [           main] pertySourcedRequestMappingHandlerMapping : Mapped URL path [/v2/api-docs] onto method [springfox.documentation.swagger2.web.Swagger2Controller#getDocumentation(String, HttpServletRequest)]
2022-01-08 14:01:52.200  INFO 8 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Creating filter chain: Ant [pattern='/v2/api-docs'], []
2022-01-08 14:01:52.207  INFO 8 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Creating filter chain: Ant [pattern='/configuration/ui'], []
2022-01-08 14:01:52.207  INFO 8 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Creating filter chain: Ant [pattern='/swagger-resources/**'], []
2022-01-08 14:01:52.207  INFO 8 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Creating filter chain: Ant [pattern='/configuration/**'], []
2022-01-08 14:01:52.207  INFO 8 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Creating filter chain: Ant [pattern='/swagger-ui**'], []
2022-01-08 14:01:52.208  INFO 8 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Creating filter chain: Ant [pattern='/webjars/**'], []
2022-01-08 14:01:52.208  INFO 8 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Creating filter chain: Ant [pattern='/lms/**'], []
2022-01-08 14:01:52.817  INFO 8 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Creating filter chain: OrRequestMatcher [requestMatchers=[Ant [pattern='/oauth/token'], Ant [pattern='/oauth/token_key'], Ant [pattern='/oauth/check_token']]], [org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter@ec3944, org.springframework.security.web.context.SecurityContextPersistenceFilter@6d6712b7, org.springframework.security.web.header.HeaderWriterFilter@24955144, org.springframework.security.web.authentication.logout.LogoutFilter@7535f28, org.springframework.security.web.authentication.www.BasicAuthenticationFilter@1c2fb9e8, org.springframework.security.web.savedrequest.RequestCacheAwareFilter@4f563f96, org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter@1feb76b9, org.springframework.security.web.authentication.AnonymousAuthenticationFilter@2e4339c1, org.springframework.security.web.session.SessionManagementFilter@71d0b8a4, org.springframework.security.web.access.ExceptionTranslationFilter@de0c402, org.springframework.security.web.access.intercept.FilterSecurityInterceptor@5f803481]
2022-01-08 14:01:52.938  INFO 8 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Creating filter chain: org.springframework.security.oauth2.config.annotation.web.configuration.ResourceServerConfiguration$NotOAuthRequestMatcher@5ebe903a, [org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter@7c88d04f, org.springframework.security.web.context.SecurityContextPersistenceFilter@54ae1240, org.springframework.security.web.header.HeaderWriterFilter@5ebf776c, org.springframework.security.web.authentication.logout.LogoutFilter@7d49a1a0, org.springframework.security.oauth2.provider.authentication.OAuth2AuthenticationProcessingFilter@16a499d1, org.springframework.security.web.savedrequest.RequestCacheAwareFilter@1c2b65cc, org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter@390a7532, org.springframework.security.web.authentication.AnonymousAuthenticationFilter@71df5f30, org.springframework.security.web.session.SessionManagementFilter@7fd3fd06, org.springframework.security.web.access.ExceptionTranslationFilter@f08f8a9, org.springframework.security.web.access.intercept.FilterSecurityInterceptor@2e62e227]
2022-01-08 14:01:52.980  INFO 8 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Creating filter chain: any request, [org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter@321b7b9e, org.springframework.security.web.context.SecurityContextPersistenceFilter@44e79e9e, org.springframework.security.web.header.HeaderWriterFilter@3664c596, org.springframework.security.web.authentication.logout.LogoutFilter@254513e8, org.springframework.security.web.savedrequest.RequestCacheAwareFilter@5bc14211, org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter@4b99648a, org.springframework.security.web.authentication.AnonymousAuthenticationFilter@21eedcde, org.springframework.security.web.session.SessionManagementFilter@40aad17d, org.springframework.security.web.access.ExceptionTranslationFilter@b529d7e, org.springframework.security.web.access.intercept.FilterSecurityInterceptor@6eab92f3]
2022-01-08 14:01:55.243  INFO 8 --- [           main] org.quartz.impl.StdSchedulerFactory      : Using default implementation for ThreadExecutor
2022-01-08 14:01:55.348  INFO 8 --- [           main] org.quartz.core.SchedulerSignalerImpl    : Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
2022-01-08 14:01:55.348  INFO 8 --- [           main] org.quartz.core.QuartzScheduler          : Quartz Scheduler v.2.3.2 created.
2022-01-08 14:01:55.365  INFO 8 --- [           main] o.s.s.quartz.LocalDataSourceJobStore     : Using db table-based data access locking (synchronization).
2022-01-08 14:01:55.379  INFO 8 --- [           main] o.s.s.quartz.LocalDataSourceJobStore     : JobStoreCMT initialized.
2022-01-08 14:01:55.382  INFO 8 --- [           main] org.quartz.core.QuartzScheduler          : Scheduler meta-data: Quartz Scheduler (v2.3.2) 'statistics scheduler' with instanceId 'NON_CLUSTERED'
  Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally.
  NOT STARTED.
  Currently in standby mode.
  Number of jobs executed: 0
  Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 1 threads.
  Using job-store 'org.springframework.scheduling.quartz.LocalDataSourceJobStore' - which supports persistence. and is not clustered.

2022-01-08 14:01:55.383  INFO 8 --- [           main] org.quartz.impl.StdSchedulerFactory      : Quartz scheduler 'statistics scheduler' initialized from an externally provided properties instance.
2022-01-08 14:01:55.383  INFO 8 --- [           main] org.quartz.impl.StdSchedulerFactory      : Quartz scheduler version: 2.3.2
2022-01-08 14:01:55.384  INFO 8 --- [           main] org.quartz.core.QuartzScheduler          : JobFactory set to: org.springframework.scheduling.quartz.SpringBeanJobFactory@4e80960a
2022-01-08 14:01:55.736  INFO 8 --- [           main] o.s.s.quartz.LocalDataSourceJobStore     : Freed 0 triggers from 'acquired' / 'blocked' state.
2022-01-08 14:01:55.751  INFO 8 --- [           main] o.s.s.quartz.LocalDataSourceJobStore     : Recovering 0 jobs that were in-progress at the time of the last shut-down.
2022-01-08 14:01:55.751  INFO 8 --- [           main] o.s.s.quartz.LocalDataSourceJobStore     : Recovery complete.
2022-01-08 14:01:55.752  INFO 8 --- [           main] o.s.s.quartz.LocalDataSourceJobStore     : Removed 0 'complete' triggers.
2022-01-08 14:01:55.753  INFO 8 --- [           main] o.s.s.quartz.LocalDataSourceJobStore     : Removed 0 stale fired job entries.
2022-01-08 14:01:55.763  INFO 8 --- [           main] org.quartz.core.QuartzScheduler          : Scheduler statistics scheduler_$_NON_CLUSTERED started.
2022-01-08 14:01:56.175  WARN 8 --- [           main] c.n.c.sources.URLConfigurationSource     : No URLs will be polled as dynamic configuration sources.
2022-01-08 14:01:56.176  INFO 8 --- [           main] c.n.c.sources.URLConfigurationSource     : To enable URLs as dynamic configuration sources, define System property archaius.configurationSource.additionalUrls or make config.properties available on classpath.
2022-01-08 14:01:56.325  WARN 8 --- [           main] c.n.c.sources.URLConfigurationSource     : No URLs will be polled as dynamic configuration sources.
2022-01-08 14:01:56.325  INFO 8 --- [           main] c.n.c.sources.URLConfigurationSource     : To enable URLs as dynamic configuration sources, define System property archaius.configurationSource.additionalUrls or make config.properties available on classpath.
2022-01-08 14:01:58.892  INFO 8 --- [           main] o.a.coyote.http11.Http11NioProtocol      : Starting ProtocolHandler ["http-nio-8080"]
2022-01-08 14:01:59.096  INFO 8 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2022-01-08 14:01:59.114  INFO 8 --- [           main] d.s.w.p.DocumentationPluginsBootstrapper : Context refreshed
2022-01-08 14:01:59.301  INFO 8 --- [           main] d.s.w.p.DocumentationPluginsBootstrapper : Found 1 custom documentation plugin(s)
2022-01-08 14:01:59.571  INFO 8 --- [           main] s.d.s.w.s.ApiListingReferenceScanner     : Scanning for api listing references
2022-01-08 14:02:00.544  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: regenerateApiKeyUsingPUT_1
2022-01-08 14:02:00.726  INFO 8 --- [           main] DeferredRepositoryInitializationListener : Triggering deferred initialization of Spring Data repositories…
2022-01-08 14:02:00.727  INFO 8 --- [           main] DeferredRepositoryInitializationListener : Spring Data repositories initialized!
2022-01-08 14:02:00.823  INFO 8 --- [           main] com.exadel.frs.FrsApplication            : Started FrsApplication in 86.842 seconds (JVM running for 92.593)
2022-01-08 14:23:57.009  INFO 8 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2022-01-08 14:23:57.029  INFO 8 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2022-01-08 14:23:57.479  INFO 8 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 447 ms

I also see a lot of errors from postgres

docker logs compreface-postgres-db

2022-01-07 23:40:54.479 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2022-01-07 23:40:54.479 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2022-01-07 23:40:54.488 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2022-01-07 23:40:54.519 UTC [24] LOG:  database system was shut down at 2022-01-07 23:26:21 UTC
2022-01-07 23:40:54.539 UTC [1] LOG:  database system is ready to accept connections
2022-01-07 23:41:29.497 UTC [32] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0
2022-01-07 23:41:30.113 UTC [34] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0
2022-01-07 23:41:30.144 UTC [36] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0
2022-01-07 23:41:32.088 UTC [38] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0
2022-01-07 23:41:32.739 UTC [40] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0
2022-01-07 23:41:32.760 UTC [42] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0
2022-01-07 23:42:03.696 UTC [33] WARNING:  there is no transaction in progress
2022-01-07 23:51:17.722 UTC [65] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0
2022-01-07 23:51:18.017 UTC [67] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0
2022-01-07 23:51:18.040 UTC [69] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0
2022-01-07 23:54:20.467 UTC [79] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0
2022-01-07 23:54:21.299 UTC [81] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0
2022-01-07 23:54:21.377 UTC [83] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0
2022-01-08 14:00:27.961 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2022-01-08 14:00:27.962 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2022-01-08 14:00:27.981 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2022-01-08 14:00:28.030 UTC [23] LOG:  database system was interrupted; last known up at 2022-01-07 23:51:00 UTC
2022-01-08 14:00:30.231 UTC [23] LOG:  database system was not properly shut down; automatic recovery in progress
2022-01-08 14:00:30.242 UTC [23] LOG:  redo starts at 0/1866380
2022-01-08 14:00:30.242 UTC [23] LOG:  invalid record length at 0/1866460: wanted 24, got 0
2022-01-08 14:00:30.242 UTC [23] LOG:  redo done at 0/1866428
2022-01-08 14:00:30.306 UTC [1] LOG:  database system is ready to accept connections
2022-01-08 14:01:01.282 UTC [30] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0
2022-01-08 14:01:02.019 UTC [32] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0
2022-01-08 14:01:02.049 UTC [34] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0
2022-01-08 14:01:06.594 UTC [36] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0
2022-01-08 14:01:07.054 UTC [38] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0
2022-01-08 14:01:07.100 UTC [40] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0
2022-01-08 14:01:54.849 UTC [31] WARNING:  there is no transaction in progress
2022-01-08 14:22:59.574 UTC [66] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0
2022-01-08 14:22:59.880 UTC [68] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0
2022-01-08 14:22:59.914 UTC [70] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0
2022-01-08 14:30:20.067 UTC [81] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0
2022-01-08 14:30:22.186 UTC [83] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0
2022-01-08 14:30:32.162 UTC [86] FATAL:  unsupported frontend protocol 1234.5680: server supports 2.0 to 3.0

I don't know if matters, but docker was eating a lot of RAM, so i created a .wslconfig file with this content

[wsl2]
processors=2
memory=1GB

I also checked and my CPU is compatible with AVX

Thank you

from compreface.

elvato87 commented on May 22, 2024

So I updated my .wslconfig file to this just to be sure and the issue persist

[wsl2]
memory=4GB

from compreface.

pospielov commented on May 22, 2024

Here is what I see from the logs:

"failed call to cuInit" - is OK, everybody has it
"FATAL: unsupported frontend protocol 1234.5680" - is OK, everybody has it
"DAMN ! worker 1 (pid: 12) died, killed by signal 9 :( trying respawn ..." - this is not OK, linux killed the process, usually it happens because of the lack of RAM.
As you can see, compreface-api was started 2 min ago and other containers are started earlier. Probably compreface-api was failed. Could you show the logs of compreface-api?

Also, 1Gb is not enough. I believe 4Gb is minimum, but I haven't tried less, probably 2Gb could be enough.

from compreface.

elvato87 commented on May 22, 2024

Hello, I updated my .wslconfig to use 4GB

[wsl2]
processors=2
memory=4GB

Here is the logs for api
docker logs compreface-api

Listening for transport dt_socket at address: 5005
2022-01-08 14:54:40.443  INFO 7 --- [kground-preinit] o.h.validator.internal.util.Version      : HV000001: Hibernate Validator 6.1.5.Final

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.3.4.RELEASE)

2022-01-08 14:54:43.270  INFO 7 --- [           main] com.exadel.frs.TrainServiceApplication   : The following profiles are active: dev
2022-01-08 14:54:47.947  INFO 7 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2022-01-08 14:54:48.528  INFO 7 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 526ms. Found 6 JPA repository interfaces.
2022-01-08 14:54:51.252  INFO 7 --- [           main] o.s.cloud.context.scope.GenericScope     : BeanFactory id=205fcd5f-0d69-3b59-9454-33cf48b1f0e2
2022-01-08 14:54:51.581  INFO 7 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'com.exadel.frs.commonservice.system.feign.ApperyStatisticsClient' of type [org.springframework.cloud.openfeign.FeignClientFactoryBean] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2022-01-08 14:54:53.514  INFO 7 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'cacheConfig' of type [com.exadel.frs.core.trainservice.config.CacheConfig$$EnhancerBySpringCGLIB$$c5626fbf] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2022-01-08 14:54:55.780  INFO 7 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2022-01-08 14:54:55.846  INFO 7 --- [           main] o.a.coyote.http11.Http11NioProtocol      : Initializing ProtocolHandler ["http-nio-8080"]
2022-01-08 14:54:55.847  INFO 7 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2022-01-08 14:54:55.848  INFO 7 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.38]
2022-01-08 14:54:56.403  INFO 7 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2022-01-08 14:54:56.404  INFO 7 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 12979 ms
2022-01-08 14:54:58.592  INFO 7 --- [           main] o.hibernate.jpa.internal.util.LogHelper  : HHH000204: Processing PersistenceUnitInfo [name: default]
2022-01-08 14:54:59.682  INFO 7 --- [           main] org.hibernate.Version                    : HHH000412: Hibernate ORM core version 5.4.21.Final
2022-01-08 14:54:59.746  INFO 7 --- [           main] org.hibernate.cfg.Environment            : HHH000205: Loaded properties from resource hibernate.properties: {hibernate.bytecode.use_reflection_optimizer=false, hibernate.types.print.banner=false}
2022-01-08 14:55:02.263  INFO 7 --- [           main] o.hibernate.annotations.common.Version   : HCANN000001: Hibernate Commons Annotations {5.1.0.Final}
2022-01-08 14:55:07.340  INFO 7 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2022-01-08 14:55:08.142  INFO 7 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
2022-01-08 14:55:08.383  INFO 7 --- [           main] org.hibernate.dialect.Dialect            : HHH000400: Using dialect: org.hibernate.dialect.PostgreSQL10Dialect
2022-01-08 14:55:15.720  INFO 7 --- [           main] o.h.e.t.j.p.i.JtaPlatformInitiator       : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2022-01-08 14:55:15.756  INFO 7 --- [           main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
2022-01-08 16:32:55.367  INFO 7 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2022-01-08 16:32:55.370  INFO 7 --- [           main] d.s.w.p.DocumentationPluginsBootstrapper : Context refreshed
2022-01-08 16:32:55.453  INFO 7 --- [           main] d.s.w.p.DocumentationPluginsBootstrapper : Found 2 custom documentation plugin(s)
2022-01-08 16:32:55.746  INFO 7 --- [           main] s.d.s.w.s.ApiListingReferenceScanner     : Scanning for api listing references
2022-01-08 16:32:56.345  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeBase64UsingPOST_1
2022-01-08 16:32:56.355  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: downloadImgUsingGET_1
2022-01-08 16:32:56.892  INFO 7 --- [           main] s.d.s.w.s.ApiListingReferenceScanner     : Scanning for api listing references
2022-01-08 16:32:56.982  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: getCheckDemoUsingGET_1
2022-01-08 16:32:57.008  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: detectUsingPOST_1
2022-01-08 16:32:57.021  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: detectBase64UsingPOST_1
2022-01-08 16:32:57.033  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: addEmbeddingUsingPOST_1
2022-01-08 16:32:57.036  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: addEmbeddingBase64UsingPOST_1
2022-01-08 16:32:57.040  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: deleteEmbeddingByIdUsingDELETE_1
2022-01-08 16:32:57.045  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: downloadImgUsingGET_2
2022-01-08 16:32:57.056  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: listEmbeddingsUsingGET_1
2022-01-08 16:32:57.072  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeBase64UsingPOST_2
2022-01-08 16:32:57.076  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeFileUsingPOST_1
2022-01-08 16:32:57.078  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: removeAllSubjectEmbeddingsUsingDELETE_1
2022-01-08 16:32:57.081  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: migrateUsingPOST_1
2022-01-08 16:32:57.087  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: handleUsingGET_1
2022-01-08 16:32:57.089  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: handleUsingGET_2
2022-01-08 16:32:57.102  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeUsingPOST_1
2022-01-08 16:32:57.112  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeBase64UsingPOST_3
2022-01-08 16:32:57.116  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: downloadImgUsingGET_3
2022-01-08 16:32:57.127  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: createSubjectUsingPOST_1
2022-01-08 16:32:57.134  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: deleteSubjectUsingDELETE_1
2022-01-08 16:32:57.136  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: deleteSubjectsUsingDELETE_1
2022-01-08 16:32:57.139  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: listSubjectsUsingGET_1
2022-01-08 16:32:57.144  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: renameSubjectUsingPUT_1
2022-01-08 16:32:57.166  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: verifyUsingPOST_1
2022-01-08 16:32:57.172  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: verifyBase64UsingPOST_1
2022-01-08 16:32:57.221  INFO 7 --- [           main] com.exadel.frs.TrainServiceApplication   : Started TrainServiceApplication in 27.912 seconds (JVM running for 30.117)
Listening for transport dt_socket at address: 5005
2022-01-10 14:02:02.265  INFO 6 --- [kground-preinit] o.h.validator.internal.util.Version      : HV000001: Hibernate Validator 6.1.5.Final

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.3.4.RELEASE)

2022-01-10 14:02:13.115  INFO 6 --- [           main] com.exadel.frs.TrainServiceApplication   : The following profiles are active: dev
2022-01-10 14:02:26.675  INFO 6 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2022-01-10 14:02:31.924  INFO 6 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 4878ms. Found 6 JPA repository interfaces.
2022-01-10 14:02:45.797  INFO 6 --- [           main] o.s.cloud.context.scope.GenericScope     : BeanFactory id=205fcd5f-0d69-3b59-9454-33cf48b1f0e2
2022-01-10 14:02:47.916  INFO 6 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'com.exadel.frs.commonservice.system.feign.ApperyStatisticsClient' of type [org.springframework.cloud.openfeign.FeignClientFactoryBean] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2022-01-10 14:02:59.601  INFO 6 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'cacheConfig' of type [com.exadel.frs.core.trainservice.config.CacheConfig$$EnhancerBySpringCGLIB$$c80b6e4] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2022-01-10 14:03:03.397  INFO 6 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2022-01-10 14:03:03.515  INFO 6 --- [           main] o.a.coyote.http11.Http11NioProtocol      : Initializing ProtocolHandler ["http-nio-8080"]
2022-01-10 14:03:03.522  INFO 6 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2022-01-10 14:03:03.523  INFO 6 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.38]
2022-01-10 14:03:04.203  INFO 6 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2022-01-10 14:03:04.203  INFO 6 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 50878 ms
2022-01-10 14:03:08.399  INFO 6 --- [           main] o.hibernate.jpa.internal.util.LogHelper  : HHH000204: Processing PersistenceUnitInfo [name: default]
2022-01-10 14:03:10.188  INFO 6 --- [           main] org.hibernate.Version                    : HHH000412: Hibernate ORM core version 5.4.21.Final
2022-01-10 14:03:10.225  INFO 6 --- [           main] org.hibernate.cfg.Environment            : HHH000205: Loaded properties from resource hibernate.properties: {hibernate.bytecode.use_reflection_optimizer=false, hibernate.types.print.banner=false}
2022-01-10 14:03:12.509  INFO 6 --- [           main] o.hibernate.annotations.common.Version   : HCANN000001: Hibernate Commons Annotations {5.1.0.Final}
2022-01-10 14:03:17.866  INFO 6 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2022-01-10 14:03:19.628  INFO 6 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
2022-01-10 14:03:20.070  INFO 6 --- [           main] org.hibernate.dialect.Dialect            : HHH000400: Using dialect: org.hibernate.dialect.PostgreSQL10Dialect
2022-01-10 14:04:05.206  INFO 6 --- [           main] o.h.e.t.j.p.i.JtaPlatformInitiator       : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2022-01-10 14:04:05.652  INFO 6 --- [           main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
2022-01-10 14:04:35.564  INFO 6 --- [           main] o.s.b.a.e.web.EndpointLinksResolver      : Exposing 2 endpoint(s) beneath base path '/actuator'
2022-01-10 14:04:36.123  INFO 6 --- [           main] pertySourcedRequestMappingHandlerMapping : Mapped URL path [/v2/api-docs] onto method [springfox.documentation.swagger2.web.Swagger2Controller#getDocumentation(String, HttpServletRequest)]
2022-01-10 14:04:36.565  INFO 6 --- [           main] org.quartz.impl.StdSchedulerFactory      : Using default implementation for ThreadExecutor
2022-01-10 14:04:36.630  INFO 6 --- [           main] org.quartz.core.SchedulerSignalerImpl    : Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
2022-01-10 14:04:36.631  INFO 6 --- [           main] org.quartz.core.QuartzScheduler          : Quartz Scheduler v.2.3.2 created.
2022-01-10 14:04:36.634  INFO 6 --- [           main] org.quartz.simpl.RAMJobStore             : RAMJobStore initialized.
2022-01-10 14:04:36.636  INFO 6 --- [           main] org.quartz.core.QuartzScheduler          : Scheduler meta-data: Quartz Scheduler (v2.3.2) 'quartzScheduler' with instanceId 'NON_CLUSTERED'
  Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally.
  NOT STARTED.
  Currently in standby mode.
  Number of jobs executed: 0
  Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 10 threads.
  Using job-store 'org.quartz.simpl.RAMJobStore' - which does not support persistence. and is not clustered.

2022-01-10 14:04:36.637  INFO 6 --- [           main] org.quartz.impl.StdSchedulerFactory      : Quartz scheduler 'quartzScheduler' initialized from an externally provided properties instance.
2022-01-10 14:04:36.637  INFO 6 --- [           main] org.quartz.impl.StdSchedulerFactory      : Quartz scheduler version: 2.3.2
2022-01-10 14:04:36.637  INFO 6 --- [           main] org.quartz.core.QuartzScheduler          : JobFactory set to: org.springframework.scheduling.quartz.SpringBeanJobFactory@74eab077
2022-01-10 14:04:36.645  INFO 6 --- [           main] org.quartz.core.QuartzScheduler          : Scheduler quartzScheduler_$_NON_CLUSTERED started.
2022-01-10 14:04:36.788  WARN 6 --- [           main] c.n.c.sources.URLConfigurationSource     : No URLs will be polled as dynamic configuration sources.
2022-01-10 14:04:36.789  INFO 6 --- [           main] c.n.c.sources.URLConfigurationSource     : To enable URLs as dynamic configuration sources, define System property archaius.configurationSource.additionalUrls or make config.properties available on classpath.
2022-01-10 14:04:36.854  WARN 6 --- [           main] c.n.c.sources.URLConfigurationSource     : No URLs will be polled as dynamic configuration sources.
2022-01-10 14:04:36.855  INFO 6 --- [           main] c.n.c.sources.URLConfigurationSource     : To enable URLs as dynamic configuration sources, define System property archaius.configurationSource.additionalUrls or make config.properties available on classpath.
2022-01-10 14:04:37.515  INFO 6 --- [           main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2022-01-10 14:04:39.262  INFO 6 --- [           main] o.a.coyote.http11.Http11NioProtocol      : Starting ProtocolHandler ["http-nio-8080"]
2022-01-10 14:04:39.372  INFO 6 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2022-01-10 14:04:39.378  INFO 6 --- [           main] d.s.w.p.DocumentationPluginsBootstrapper : Context refreshed
2022-01-10 14:04:39.625  INFO 6 --- [           main] d.s.w.p.DocumentationPluginsBootstrapper : Found 2 custom documentation plugin(s)
2022-01-10 14:04:40.278  INFO 6 --- [           main] s.d.s.w.s.ApiListingReferenceScanner     : Scanning for api listing references
2022-01-10 14:04:41.434  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeBase64UsingPOST_1
2022-01-10 14:04:41.443  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: downloadImgUsingGET_1
2022-01-10 14:04:42.608  INFO 6 --- [           main] s.d.s.w.s.ApiListingReferenceScanner     : Scanning for api listing references
2022-01-10 14:04:42.683  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: getCheckDemoUsingGET_1
2022-01-10 14:04:42.725  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: detectUsingPOST_1
2022-01-10 14:04:42.747  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: detectBase64UsingPOST_1
2022-01-10 14:04:42.757  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: addEmbeddingUsingPOST_1
2022-01-10 14:04:42.769  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: addEmbeddingBase64UsingPOST_1
2022-01-10 14:04:42.772  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: deleteEmbeddingByIdUsingDELETE_1
2022-01-10 14:04:42.777  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: downloadImgUsingGET_2
2022-01-10 14:04:42.786  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: listEmbeddingsUsingGET_1
2022-01-10 14:04:42.803  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeBase64UsingPOST_2
2022-01-10 14:04:42.806  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeFileUsingPOST_1
2022-01-10 14:04:42.810  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: removeAllSubjectEmbeddingsUsingDELETE_1
2022-01-10 14:04:42.814  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: migrateUsingPOST_1
2022-01-10 14:04:42.822  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: handleUsingGET_1
2022-01-10 14:04:42.824  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: handleUsingGET_2
2022-01-10 14:04:42.840  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeUsingPOST_1
2022-01-10 14:04:42.847  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeBase64UsingPOST_3
2022-01-10 14:04:42.852  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: downloadImgUsingGET_3
2022-01-10 14:04:42.860  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: createSubjectUsingPOST_1
2022-01-10 14:04:42.864  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: deleteSubjectUsingDELETE_1
2022-01-10 14:04:42.867  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: deleteSubjectsUsingDELETE_1
2022-01-10 14:04:42.869  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: listSubjectsUsingGET_1
2022-01-10 14:04:42.871  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: renameSubjectUsingPUT_1
2022-01-10 14:04:42.890  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: verifyUsingPOST_1
2022-01-10 14:04:42.905  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: verifyBase64UsingPOST_1
2022-01-10 14:04:42.978  INFO 6 --- [           main] com.exadel.frs.TrainServiceApplication   : Started TrainServiceApplication in 173.247 seconds (JVM running for 188.138)
Listening for transport dt_socket at address: 5005
2022-01-10 15:50:48.700  INFO 8 --- [kground-preinit] o.h.validator.internal.util.Version      : HV000001: Hibernate Validator 6.1.5.Final

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.3.4.RELEASE)

2022-01-10 15:50:52.009  INFO 8 --- [           main] com.exadel.frs.TrainServiceApplication   : The following profiles are active: dev
2022-01-10 15:50:56.685  INFO 8 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2022-01-10 15:50:57.160  INFO 8 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 428ms. Found 6 JPA repository interfaces.
2022-01-10 15:50:59.772  INFO 8 --- [           main] o.s.cloud.context.scope.GenericScope     : BeanFactory id=205fcd5f-0d69-3b59-9454-33cf48b1f0e2
2022-01-10 15:51:00.083  INFO 8 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'com.exadel.frs.commonservice.system.feign.ApperyStatisticsClient' of type [org.springframework.cloud.openfeign.FeignClientFactoryBean] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2022-01-10 15:51:01.479  INFO 8 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'cacheConfig' of type [com.exadel.frs.core.trainservice.config.CacheConfig$$EnhancerBySpringCGLIB$$11a92915] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2022-01-10 15:51:03.388  INFO 8 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2022-01-10 15:51:03.427  INFO 8 --- [           main] o.a.coyote.http11.Http11NioProtocol      : Initializing ProtocolHandler ["http-nio-8080"]
2022-01-10 15:51:03.435  INFO 8 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2022-01-10 15:51:03.435  INFO 8 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.38]
2022-01-10 15:51:03.768  INFO 8 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2022-01-10 15:51:03.784  INFO 8 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 11618 ms
2022-01-10 15:51:05.489  INFO 8 --- [           main] o.hibernate.jpa.internal.util.LogHelper  : HHH000204: Processing PersistenceUnitInfo [name: default]
2022-01-10 15:51:06.124  INFO 8 --- [           main] org.hibernate.Version                    : HHH000412: Hibernate ORM core version 5.4.21.Final
2022-01-10 15:51:06.128  INFO 8 --- [           main] org.hibernate.cfg.Environment            : HHH000205: Loaded properties from resource hibernate.properties: {hibernate.bytecode.use_reflection_optimizer=false, hibernate.types.print.banner=false}
2022-01-10 15:51:07.253  INFO 8 --- [           main] o.hibernate.annotations.common.Version   : HCANN000001: Hibernate Commons Annotations {5.1.0.Final}
2022-01-10 15:51:09.679  INFO 8 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2022-01-10 15:51:10.088  INFO 8 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
2022-01-10 15:51:10.189  INFO 8 --- [           main] org.hibernate.dialect.Dialect            : HHH000400: Using dialect: org.hibernate.dialect.PostgreSQL10Dialect
2022-01-10 15:51:15.791  INFO 8 --- [           main] o.h.e.t.j.p.i.JtaPlatformInitiator       : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2022-01-10 15:51:15.819  INFO 8 --- [           main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
2022-01-10 15:51:30.740  INFO 8 --- [           main] o.s.b.a.e.web.EndpointLinksResolver      : Exposing 2 endpoint(s) beneath base path '/actuator'
2022-01-10 15:51:31.199  INFO 8 --- [           main] pertySourcedRequestMappingHandlerMapping : Mapped URL path [/v2/api-docs] onto method [springfox.documentation.swagger2.web.Swagger2Controller#getDocumentation(String, HttpServletRequest)]
2022-01-10 15:51:31.467  INFO 8 --- [           main] org.quartz.impl.StdSchedulerFactory      : Using default implementation for ThreadExecutor
2022-01-10 15:51:31.551  INFO 8 --- [           main] org.quartz.core.SchedulerSignalerImpl    : Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
2022-01-10 15:51:31.551  INFO 8 --- [           main] org.quartz.core.QuartzScheduler          : Quartz Scheduler v.2.3.2 created.
2022-01-10 15:51:31.552  INFO 8 --- [           main] org.quartz.simpl.RAMJobStore             : RAMJobStore initialized.
2022-01-10 15:51:31.566  INFO 8 --- [           main] org.quartz.core.QuartzScheduler          : Scheduler meta-data: Quartz Scheduler (v2.3.2) 'quartzScheduler' with instanceId 'NON_CLUSTERED'
  Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally.
  NOT STARTED.
  Currently in standby mode.
  Number of jobs executed: 0
  Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 10 threads.
  Using job-store 'org.quartz.simpl.RAMJobStore' - which does not support persistence. and is not clustered.

2022-01-10 15:51:31.567  INFO 8 --- [           main] org.quartz.impl.StdSchedulerFactory      : Quartz scheduler 'quartzScheduler' initialized from an externally provided properties instance.
2022-01-10 15:51:31.567  INFO 8 --- [           main] org.quartz.impl.StdSchedulerFactory      : Quartz scheduler version: 2.3.2
2022-01-10 15:51:31.568  INFO 8 --- [           main] org.quartz.core.QuartzScheduler          : JobFactory set to: org.springframework.scheduling.quartz.SpringBeanJobFactory@10dbf660
2022-01-10 15:51:31.604  INFO 8 --- [           main] org.quartz.core.QuartzScheduler          : Scheduler quartzScheduler_$_NON_CLUSTERED started.
2022-01-10 15:51:31.692  WARN 8 --- [           main] c.n.c.sources.URLConfigurationSource     : No URLs will be polled as dynamic configuration sources.
2022-01-10 15:51:31.692  INFO 8 --- [           main] c.n.c.sources.URLConfigurationSource     : To enable URLs as dynamic configuration sources, define System property archaius.configurationSource.additionalUrls or make config.properties available on classpath.
2022-01-10 15:51:31.722  WARN 8 --- [           main] c.n.c.sources.URLConfigurationSource     : No URLs will be polled as dynamic configuration sources.
2022-01-10 15:51:31.722  INFO 8 --- [           main] c.n.c.sources.URLConfigurationSource     : To enable URLs as dynamic configuration sources, define System property archaius.configurationSource.additionalUrls or make config.properties available on classpath.
2022-01-10 15:51:32.127  INFO 8 --- [           main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2022-01-10 15:51:33.566  INFO 8 --- [           main] o.a.coyote.http11.Http11NioProtocol      : Starting ProtocolHandler ["http-nio-8080"]
2022-01-10 15:51:33.668  INFO 8 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2022-01-10 15:51:33.689  INFO 8 --- [           main] d.s.w.p.DocumentationPluginsBootstrapper : Context refreshed
2022-01-10 15:51:33.763  INFO 8 --- [           main] d.s.w.p.DocumentationPluginsBootstrapper : Found 2 custom documentation plugin(s)
2022-01-10 15:51:34.191  INFO 8 --- [           main] s.d.s.w.s.ApiListingReferenceScanner     : Scanning for api listing references
2022-01-10 15:51:35.661  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeBase64UsingPOST_1
2022-01-10 15:51:35.683  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: downloadImgUsingGET_1
2022-01-10 15:51:36.059  INFO 8 --- [           main] s.d.s.w.s.ApiListingReferenceScanner     : Scanning for api listing references
2022-01-10 15:51:36.247  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: getCheckDemoUsingGET_1
2022-01-10 15:51:36.495  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: detectUsingPOST_1
2022-01-10 15:51:36.525  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: detectBase64UsingPOST_1
2022-01-10 15:51:36.540  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: addEmbeddingUsingPOST_1
2022-01-10 15:51:36.692  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: addEmbeddingBase64UsingPOST_1
2022-01-10 15:51:36.695  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: deleteEmbeddingByIdUsingDELETE_1
2022-01-10 15:51:36.699  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: downloadImgUsingGET_2
2022-01-10 15:51:36.735  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: listEmbeddingsUsingGET_1
2022-01-10 15:51:36.824  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeBase64UsingPOST_2
2022-01-10 15:51:36.828  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeFileUsingPOST_1
2022-01-10 15:51:36.830  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: removeAllSubjectEmbeddingsUsingDELETE_1
2022-01-10 15:51:36.833  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: migrateUsingPOST_1
2022-01-10 15:51:36.872  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: handleUsingGET_1
2022-01-10 15:51:36.877  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: handleUsingGET_2
2022-01-10 15:51:36.903  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeUsingPOST_1
2022-01-10 15:51:36.926  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeBase64UsingPOST_3
2022-01-10 15:51:36.930  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: downloadImgUsingGET_3
2022-01-10 15:51:36.958  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: createSubjectUsingPOST_1
2022-01-10 15:51:36.961  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: deleteSubjectUsingDELETE_1
2022-01-10 15:51:36.963  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: deleteSubjectsUsingDELETE_1
2022-01-10 15:51:36.969  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: listSubjectsUsingGET_1
2022-01-10 15:51:36.972  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: renameSubjectUsingPUT_1
2022-01-10 15:51:37.042  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: verifyUsingPOST_1
2022-01-10 15:51:37.064  INFO 8 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: verifyBase64UsingPOST_1
2022-01-10 15:51:37.211  INFO 8 --- [           main] com.exadel.frs.TrainServiceApplication   : Started TrainServiceApplication in 56.461 seconds (JVM running for 63.805)

from compreface.

pospielov commented on May 22, 2024

There are no errors in those logs. Did you copy the logs before or after getting the 502 error code?

from compreface.

elvato87 commented on May 22, 2024

I copied them after getting the error

from compreface.

elvato87 commented on May 22, 2024

I tried again and now it's working, i have no idea why

from compreface.

elvato87 commented on May 22, 2024

Thank you for your help

from compreface.

lordratner commented on May 22, 2024

Hi there. I'm getting this error and I can't figure out why.

When I first log into CF I can navigate around fine, however once I open one application on the dashboard, I get kicked back to the dashboard and get the 502 error trying to open any application.

My Double-Take instance is also getting the 502 error. I tried removing all 5 docker containers and rebuilding, but it's the same error. Here are the various logs

Core:

*** Starting uWSGI 2.0.19 (64bit) on [Sun Oct 23 22:22:17 2022] ***
compiled with version: 10.2.1 20210110 on 07 October 2022 08:24:18
os: Linux-5.15.60-1-pve #1 SMP PVE 5.15.60-1 (Mon, 19 Sep 2022 17:53:17 +0200)
nodename: d5679af2275d
machine: x86_64
clock source: unix
detected number of CPU cores: 4
current working directory: /app/ml
detected binary path: /usr/local/bin/uwsgi
!!! no internal routing support, rebuild with pcre support !!!
setgid() to 33
setuid() to 33
your processes number limit is 63411
your memory page size is 4096 bytes
detected max file descriptor number: 524288
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uwsgi socket 0 bound to TCP address 0.0.0.0:3000 fd 3
Python version: 3.7.14 (default, Oct  5 2022, 16:16:25)  [GCC 10.2.1 20210110]
Python main interpreter initialized at 0x559f3cbd4e80
python threads support enabled
your server socket listen backlog is limited to 100 connections
your mercy for graceful operations on workers is 60 seconds
mapped 218712 bytes (213 KB) for 2 cores
*** Operational MODE: preforking ***
{"severity": "INFO", "message": "{'BUILD_VERSION': 'dev', 'CALCULATION_PLUGIN': 'facenet.Calculator', 'EXTRA_PLUGINS': ['facenet.LandmarksDetector', 'agegender.AgeDetector', 'agegender.GenderDetector', 'facenet.facemask.MaskDetector', 'facenet.PoseEstimator'], 'FACE_DETECTION_PLUGIN': 'facenet.FaceDetector', 'GPU_IDX': -1, 'IMG_LENGTH_LIMIT': 640, 'INTEL_OPTIMIZATION': False, 'IS_DEV_ENV': False, 'LOGGING_LEVEL_NAME': 'DEBUG', 'ML_PORT': 3000, 'RUN_MODE': True}", "request": null, "logger": "src.app", "module": "app", "traceback": null, "build_version": "dev"}
{"severity": "DEBUG", "message": "Creating new app for WSGI", "request": null, "logger": "src.app", "module": "app", "traceback": null, "build_version": "dev"}
WSGI app 0 (mountpoint='') ready in 4 seconds on interpreter 0x559f3cbd4e80 pid: 1 (default app)
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI master process (pid: 1)
spawned uWSGI worker 1 (pid: 10, cores: 1)
spawned uWSGI worker 2 (pid: 11, cores: 1)
{"severity": "INFO", "message": "200 OK", "request": {"method": "GET", "path": "/status", "filename": "", "api_key": "", "remote_addr": "172.18.0.6"}, "logger": "src.services.flask_.log_response", "module": "log_response", "traceback": null, "build_version": "dev"}
{"severity": "INFO", "message": "200 OK", "request": {"method": "GET", "path": "/status", "filename": "", "api_key": "", "remote_addr": "172.18.0.4"}, "logger": "src.services.flask_.log_response", "module": "log_response", "traceback": null, "build_version": "dev"}
2022-10-23 22:23:42.331335: E tensorflow/stream_executor/cuda/cuda_driver.cc:351] failed call to cuInit: UNKNOWN ERROR (303)
{"severity": "DEBUG", "message": "Found: BoundingBoxDTO(x_min=173, y_min=158, x_max=386, y_max=417, probability=0.9265304207801819, _np_landmarks=array([[266, 264],\n       [333, 266],\n       [313, 320],\n       [268, 350],\n       [318, 351]]))", "request": {"method": "POST", "path": "/find_faces", "filename": "lenna.jpg", "api_key": "", "remote_addr": "172.18.0.4"}, "logger": "src.services.facescan.plugins.facenet.facenet", "module": "facenet", "traceback": null, "build_version": "dev"}
{"severity": "INFO", "message": "200 OK", "request": {"method": "POST", "path": "/find_faces", "filename": "lenna.jpg", "api_key": "", "remote_addr": "172.18.0.4"}, "logger": "src.services.flask_.log_response", "module": "log_response", "traceback": null, "build_version": "dev"}
{"severity": "DEBUG", "message": "Found: BoundingBoxDTO(x_min=173, y_min=158, x_max=386, y_max=417, probability=0.9265304207801819, _np_landmarks=array([[266, 264],\n       [333, 266],\n       [313, 320],\n       [268, 350],\n       [318, 351]]))", "request": {"method": "POST", "path": "/find_faces", "filename": "lenna.jpg", "api_key": "", "remote_addr": "172.18.0.4"}, "logger": "src.services.facescan.plugins.facenet.facenet", "module": "facenet", "traceback": null, "build_version": "dev"}
{"severity": "INFO", "message": "200 OK", "request": {"method": "POST", "path": "/find_faces", "filename": "lenna.jpg", "api_key": "", "remote_addr": "172.18.0.4"}, "logger": "src.services.flask_.log_response", "module": "log_response", "traceback": null, "build_version": "dev"}

UI (you can see the connection refused errors in here:

/docker-entrypoint.sh: /docker-entrypoint.d/ is not empty, will attempt to perform configuration
/docker-entrypoint.sh: Looking for shell scripts in /docker-entrypoint.d/
/docker-entrypoint.sh: Launching /docker-entrypoint.d/10-listen-on-ipv6-by-default.sh
10-listen-on-ipv6-by-default.sh: info: /etc/nginx/conf.d/default.conf is not a file or does not exist
/docker-entrypoint.sh: Launching /docker-entrypoint.d/20-envsubst-on-templates.sh
20-envsubst-on-templates.sh: Running envsubst on /etc/nginx/templates/nginx.conf.template to /etc/nginx/conf.d/nginx.conf
/docker-entrypoint.sh: Launching /docker-entrypoint.d/30-tune-worker-processes.sh
/docker-entrypoint.sh: Configuration complete; ready for start up
2022/10/23 22:23:03 [error] 26#26: *1 connect() failed (111: Connection refused) while connecting to upstream, client: 192.168.20.41, server: ui, request: "GET /api/v1/consistence/status HTTP/1.1", upstream: "http://172.18.0.4:8080/api/v1/consistence/status", host: "192.168.20.111:8000", referrer: "http://192.168.20.111:8000/login"
192.168.20.41 - - [23/Oct/2022:22:23:03 +0000] "GET /api/v1/consistence/status HTTP/1.1" 502 552 "http://192.168.20.111:8000/login" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
192.168.20.41 - CommonClientId [23/Oct/2022:22:23:28 +0000] "POST /admin/oauth/token HTTP/1.1" 200 0 "http://192.168.20.111:8000/login" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
192.168.20.41 - - [23/Oct/2022:22:23:28 +0000] "GET /admin/user/me HTTP/1.1" 200 130 "http://192.168.20.111:8000/login" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
192.168.20.41 - - [23/Oct/2022:22:23:28 +0000] "GET /admin/user/roles HTTP/1.1" 200 144 "http://192.168.20.111:8000/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
192.168.20.41 - - [23/Oct/2022:22:23:29 +0000] "GET /admin/apps HTTP/1.1" 200 331 "http://192.168.20.111:8000/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
192.168.20.41 - - [23/Oct/2022:22:23:29 +0000] "GET /api/v1/config HTTP/1.1" 200 83 "http://192.168.20.111:8000/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
192.168.20.41 - - [23/Oct/2022:22:23:30 +0000] "GET /core/status HTTP/1.1" 200 240 "http://192.168.20.111:8000/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
192.168.20.41 - - [23/Oct/2022:22:23:31 +0000] "GET /admin/user/roles HTTP/1.1" 200 144 "http://192.168.20.111:8000/application?app=15a8fc2a-9002-4b38-b4a1-027e1e708de9" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
192.168.20.41 - - [23/Oct/2022:22:23:31 +0000] "GET /admin/app/15a8fc2a-9002-4b38-b4a1-027e1e708de9/roles HTTP/1.1" 200 144 "http://192.168.20.111:8000/application?app=15a8fc2a-9002-4b38-b4a1-027e1e708de9" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
192.168.20.41 - - [23/Oct/2022:22:23:31 +0000] "GET /admin/app/15a8fc2a-9002-4b38-b4a1-027e1e708de9/models HTTP/1.1" 200 202 "http://192.168.20.111:8000/application?app=15a8fc2a-9002-4b38-b4a1-027e1e708de9" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
192.168.20.41 - - [23/Oct/2022:22:23:32 +0000] "GET /api/v1/consistence/status HTTP/1.1" 200 105 "http://192.168.20.111:8000/application?app=15a8fc2a-9002-4b38-b4a1-027e1e708de9" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
2022/10/23 22:23:44 [error] 26#26: *16 upstream prematurely closed connection while reading response header from upstream, client: 192.168.20.112, server: ui, request: "POST /api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8 HTTP/1.1", upstream: "http://172.18.0.4:8080/api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8", host: "192.168.20.111:8000"
192.168.20.112 - - [23/Oct/2022:22:23:44 +0000] "POST /api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8 HTTP/1.1" 502 150 "-" "axios/0.27.2"
192.168.20.41 - - [23/Oct/2022:22:24:07 +0000] "GET /admin/user/roles HTTP/1.1" 200 144 "http://192.168.20.111:8000/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
192.168.20.41 - - [23/Oct/2022:22:24:07 +0000] "GET /admin/apps HTTP/1.1" 200 331 "http://192.168.20.111:8000/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
192.168.20.41 - - [23/Oct/2022:22:24:11 +0000] "GET /admin/user/roles HTTP/1.1" 200 144 "http://192.168.20.111:8000/application?app=15a8fc2a-9002-4b38-b4a1-027e1e708de9" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
2022/10/23 22:24:11 [error] 26#26: *23 recv() failed (104: Connection reset by peer) while reading response header from upstream, client: 192.168.20.112, server: ui, request: "POST /api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8 HTTP/1.1", upstream: "http://172.18.0.4:8080/api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8", host: "192.168.20.111:8000"
192.168.20.112 - - [23/Oct/2022:22:24:11 +0000] "POST /api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8 HTTP/1.1" 502 150 "-" "axios/0.27.2"
192.168.20.41 - - [23/Oct/2022:22:24:11 +0000] "GET /admin/app/15a8fc2a-9002-4b38-b4a1-027e1e708de9/roles HTTP/1.1" 200 144 "http://192.168.20.111:8000/application?app=15a8fc2a-9002-4b38-b4a1-027e1e708de9" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
192.168.20.41 - - [23/Oct/2022:22:24:11 +0000] "GET /admin/app/15a8fc2a-9002-4b38-b4a1-027e1e708de9/models HTTP/1.1" 200 202 "http://192.168.20.111:8000/application?app=15a8fc2a-9002-4b38-b4a1-027e1e708de9" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
192.168.20.41 - - [23/Oct/2022:22:24:11 +0000] "GET /api/v1/consistence/status HTTP/1.1" 502 552 "http://192.168.20.111:8000/application?app=15a8fc2a-9002-4b38-b4a1-027e1e708de9" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
2022/10/23 22:24:11 [error] 26#26: *6 connect() failed (111: Connection refused) while connecting to upstream, client: 192.168.20.41, server: ui, request: "GET /api/v1/consistence/status HTTP/1.1", upstream: "http://172.18.0.4:8080/api/v1/consistence/status", host: "192.168.20.111:8000", referrer: "http://192.168.20.111:8000/application?app=15a8fc2a-9002-4b38-b4a1-027e1e708de9"
192.168.20.41 - - [23/Oct/2022:22:24:11 +0000] "GET /admin/user/roles HTTP/1.1" 200 144 "http://192.168.20.111:8000/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
192.168.20.41 - - [23/Oct/2022:22:24:11 +0000] "GET /admin/apps HTTP/1.1" 200 331 "http://192.168.20.111:8000/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
192.168.20.41 - - [23/Oct/2022:22:24:13 +0000] "GET /admin/app/15a8fc2a-9002-4b38-b4a1-027e1e708de9/models HTTP/1.1" 499 0 "http://192.168.20.111:8000/application?app=a7bb7074-b503-45fc-83f8-88cd84227fb2" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
192.168.20.41 - - [23/Oct/2022:22:24:13 +0000] "GET /admin/app/15a8fc2a-9002-4b38-b4a1-027e1e708de9/roles HTTP/1.1" 499 0 "http://192.168.20.111:8000/application?app=a7bb7074-b503-45fc-83f8-88cd84227fb2" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
192.168.20.41 - - [23/Oct/2022:22:24:13 +0000] "GET /admin/user/roles HTTP/1.1" 499 0 "http://192.168.20.111:8000/application?app=a7bb7074-b503-45fc-83f8-88cd84227fb2" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
192.168.20.41 - - [23/Oct/2022:22:24:13 +0000] "GET /admin/user/roles HTTP/1.1" 200 144 "http://192.168.20.111:8000/application?app=a7bb7074-b503-45fc-83f8-88cd84227fb2" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
192.168.20.41 - - [23/Oct/2022:22:24:13 +0000] "GET /admin/app/a7bb7074-b503-45fc-83f8-88cd84227fb2/models HTTP/1.1" 200 33 "http://192.168.20.111:8000/application?app=a7bb7074-b503-45fc-83f8-88cd84227fb2" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
192.168.20.41 - - [23/Oct/2022:22:24:13 +0000] "GET /admin/app/a7bb7074-b503-45fc-83f8-88cd84227fb2/roles HTTP/1.1" 200 144 "http://192.168.20.111:8000/application?app=a7bb7074-b503-45fc-83f8-88cd84227fb2" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
2022/10/23 22:24:13 [error] 26#26: *32 connect() failed (111: Connection refused) while connecting to upstream, client: 192.168.20.41, server: ui, request: "GET /api/v1/consistence/status HTTP/1.1", upstream: "http://172.18.0.4:8080/api/v1/consistence/status", host: "192.168.20.111:8000", referrer: "http://192.168.20.111:8000/application?app=a7bb7074-b503-45fc-83f8-88cd84227fb2"
192.168.20.41 - - [23/Oct/2022:22:24:13 +0000] "GET /api/v1/consistence/status HTTP/1.1" 502 552 "http://192.168.20.111:8000/application?app=a7bb7074-b503-45fc-83f8-88cd84227fb2" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
192.168.20.41 - - [23/Oct/2022:22:24:13 +0000] "GET /admin/user/roles HTTP/1.1" 200 144 "http://192.168.20.111:8000/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
192.168.20.41 - - [23/Oct/2022:22:24:13 +0000] "GET /admin/apps HTTP/1.1" 200 331 "http://192.168.20.111:8000/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/106.0.0.0 Safari/537.36"
2022/10/23 22:24:41 [error] 26#26: *39 connect() failed (111: Connection refused) while connecting to upstream, client: 192.168.20.112, server: ui, request: "POST /api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8 HTTP/1.1", upstream: "http://172.18.0.4:8080/api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8", host: "192.168.20.111:8000"
192.168.20.112 - - [23/Oct/2022:22:24:41 +0000] "POST /api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8 HTTP/1.1" 502 150 "-" "axios/0.27.2"
2022/10/23 22:25:24 [error] 26#26: *41 upstream prematurely closed connection while reading response header from upstream, client: 192.168.20.112, server: ui, request: "POST /api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8 HTTP/1.1", upstream: "http://172.18.0.4:8080/api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8", host: "192.168.20.111:8000"
192.168.20.112 - - [23/Oct/2022:22:25:24 +0000] "POST /api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8 HTTP/1.1" 502 150 "-" "axios/0.27.2"
2022/10/23 22:25:41 [error] 26#26: *43 connect() failed (111: Connection refused) while connecting to upstream, client: 192.168.20.112, server: ui, request: "POST /api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8 HTTP/1.1", upstream: "http://172.18.0.4:8080/api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8", host: "192.168.20.111:8000"
192.168.20.112 - - [23/Oct/2022:22:25:41 +0000] "POST /api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8 HTTP/1.1" 502 150 "-" "axios/0.27.2"
192.168.20.112 - - [23/Oct/2022:22:26:11 +0000] "POST /api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8 HTTP/1.1" 502 150 "-" "axios/0.27.2"
2022/10/23 22:26:11 [error] 26#26: *45 connect() failed (111: Connection refused) while connecting to upstream, client: 192.168.20.112, server: ui, request: "POST /api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8 HTTP/1.1", upstream: "http://172.18.0.4:8080/api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8", host: "192.168.20.111:8000"
2022/10/23 22:26:41 [error] 26#26: *47 connect() failed (111: Connection refused) while connecting to upstream, client: 192.168.20.112, server: ui, request: "POST /api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8 HTTP/1.1", upstream: "http://172.18.0.4:8080/api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8", host: "192.168.20.111:8000"
192.168.20.112 - - [23/Oct/2022:22:26:41 +0000] "POST /api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8 HTTP/1.1" 502 150 "-" "axios/0.27.2"
2022/10/23 22:27:11 [error] 26#26: *49 connect() failed (111: Connection refused) while connecting to upstream, client: 192.168.20.112, server: ui, request: "POST /api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8 HTTP/1.1", upstream: "http://172.18.0.4:8080/api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8", host: "192.168.20.111:8000"
192.168.20.112 - - [23/Oct/2022:22:27:11 +0000] "POST /api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8 HTTP/1.1" 502 150 "-" "axios/0.27.2"`

Postgres:

2022-10-23 22:22:17.727 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2022-10-23 22:22:17.727 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2022-10-23 22:22:17.732 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2022-10-23 22:22:17.746 UTC [23] LOG:  database system was shut down at 2022-10-23 22:16:24 UTC
2022-10-23 22:22:17.777 UTC [1] LOG:  database system is ready to accept connections
2022-10-23 22:22:41.354 UTC [30] WARNING:  there is no transaction in progress

Admin:

Listening for transport dt_socket at address: 5005
  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::               (v2.5.13)
2022-10-23 22:22:26.332  INFO 6 --- [kground-preinit] o.h.validator.internal.util.Version      : HV000001: Hibernate Validator 6.2.3.Final
2022-10-23 22:22:26.415  INFO 6 --- [           main] com.exadel.frs.FrsApplication            : Starting FrsApplication v0.0.1-SNAPSHOT using Java 11.0.8 on 3b8f7d9aef94 with PID 6 (/home/app.jar started by root in /)
2022-10-23 22:22:26.416 DEBUG 6 --- [           main] com.exadel.frs.FrsApplication            : Running with Spring Boot v2.5.13, Spring v5.3.19
2022-10-23 22:22:26.417  INFO 6 --- [           main] com.exadel.frs.FrsApplication            : The following 1 profile is active: "dev"
2022-10-23 22:22:32.051  INFO 6 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2022-10-23 22:22:32.397  INFO 6 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 326 ms. Found 11 JPA repository interfaces.
2022-10-23 22:22:33.234  INFO 6 --- [           main] o.s.cloud.context.scope.GenericScope     : BeanFactory id=87eecb33-b947-31b8-bbb7-8d063df92185
2022-10-23 22:22:35.418  INFO 6 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2022-10-23 22:22:35.455  INFO 6 --- [           main] o.a.coyote.http11.Http11NioProtocol      : Initializing ProtocolHandler ["http-nio-8080"]
2022-10-23 22:22:35.455  INFO 6 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2022-10-23 22:22:35.456  INFO 6 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.62]
2022-10-23 22:22:35.730  INFO 6 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2022-10-23 22:22:35.743  INFO 6 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 9093 ms
2022-10-23 22:22:37.421  INFO 6 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2022-10-23 22:22:37.896  INFO 6 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
2022-10-23 22:22:38.430  INFO 6 --- [           main] liquibase.database                       : Set default schema name to public
2022-10-23 22:22:38.751  INFO 6 --- [           main] liquibase.lockservice                    : Successfully acquired change log lock
2022-10-23 22:22:40.400  INFO 6 --- [           main] liquibase.changelog                      : Reading from public.databasechangelog
2022-10-23 22:22:40.849  INFO 6 --- [           main] liquibase.lockservice                    : Successfully released change log lock
2022-10-23 22:22:41.647  INFO 6 --- [           main] o.hibernate.jpa.internal.util.LogHelper  : HHH000204: Processing PersistenceUnitInfo [name: default]
2022-10-23 22:22:41.915  INFO 6 --- [           main] org.hibernate.Version                    : HHH000412: Hibernate ORM core version 5.4.33
2022-10-23 22:22:42.492  INFO 6 --- [           main] o.hibernate.annotations.common.Version   : HCANN000001: Hibernate Commons Annotations {5.1.2.Final}
2022-10-23 22:22:43.165  INFO 6 --- [           main] org.hibernate.dialect.Dialect            : HHH000400: Using dialect: org.hibernate.dialect.PostgreSQL10Dialect
2022-10-23 22:22:43.333  INFO 6 --- [           main] Hibernate Types                          : This framework is proudly powered by:
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 _    _                           _     _
| |  | |                         (_)   | |
| |__| |_   _ _ __   ___ _ __ ___ _ ___| |_ ___ _ __   ___ ___
|  __  | | | | '_ \ / _ \ '__/ __| / __| __/ _ \ '_ \ / __/ _ \
| |  | | |_| | |_) |  __/ |  \__ \ \__ \ ||  __/ | | | (_|  __/
|_|  |_|\__, | .__/ \___|_|  |___/_|___/\__\___|_| |_|\___\___|
         __/ | |
        |___/|_|
At Hypersistence, we only build amazing tools, like Hibernate Types, Flexy Pool, or Hypersistence Optimizer.
What if there were a tool that could automatically detect JPA and Hibernate performance issues?
Hypersistence Optimizer is that tool! For more details, go to: 
https://vladmihalcea.com/hypersistence-optimizer/
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2022-10-23 22:22:46.982  INFO 6 --- [           main] o.h.e.t.j.p.i.JtaPlatformInitiator       : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2022-10-23 22:22:47.015  INFO 6 --- [           main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
2022-10-23 22:22:53.570  INFO 6 --- [           main] o.s.b.a.e.web.EndpointLinksResolver      : Exposing 1 endpoint(s) beneath base path '/actuator'
2022-10-23 22:22:55.210  WARN 6 --- [           main] o.s.s.c.a.web.builders.WebSecurity       : You are asking Spring Security to ignore Ant [pattern='/v2/api-docs']. This is not recommended -- please use permitAll via HttpSecurity#authorizeHttpRequests instead.
2022-10-23 22:22:55.224  INFO 6 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Will secure Ant [pattern='/v2/api-docs'] with []
2022-10-23 22:22:55.224  WARN 6 --- [           main] o.s.s.c.a.web.builders.WebSecurity       : You are asking Spring Security to ignore Ant [pattern='/configuration/ui']. This is not recommended -- please use permitAll via HttpSecurity#authorizeHttpRequests instead.
2022-10-23 22:22:55.224  INFO 6 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Will secure Ant [pattern='/configuration/ui'] with []
2022-10-23 22:22:55.225  WARN 6 --- [           main] o.s.s.c.a.web.builders.WebSecurity       : You are asking Spring Security to ignore Ant [pattern='/swagger-resources/**']. This is not recommended -- please use permitAll via HttpSecurity#authorizeHttpRequests instead.
2022-10-23 22:22:55.225  INFO 6 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Will secure Ant [pattern='/swagger-resources/**'] with []
2022-10-23 22:22:55.225  WARN 6 --- [           main] o.s.s.c.a.web.builders.WebSecurity       : You are asking Spring Security to ignore Ant [pattern='/configuration/**']. This is not recommended -- please use permitAll via HttpSecurity#authorizeHttpRequests instead.
2022-10-23 22:22:55.225  INFO 6 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Will secure Ant [pattern='/configuration/**'] with []
2022-10-23 22:22:55.225  WARN 6 --- [           main] o.s.s.c.a.web.builders.WebSecurity       : You are asking Spring Security to ignore Ant [pattern='/swagger-ui**']. This is not recommended -- please use permitAll via HttpSecurity#authorizeHttpRequests instead.
2022-10-23 22:22:55.225  INFO 6 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Will secure Ant [pattern='/swagger-ui**'] with []
2022-10-23 22:22:55.225  WARN 6 --- [           main] o.s.s.c.a.web.builders.WebSecurity       : You are asking Spring Security to ignore Ant [pattern='/webjars/**']. This is not recommended -- please use permitAll via HttpSecurity#authorizeHttpRequests instead.
2022-10-23 22:22:55.225  INFO 6 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Will secure Ant [pattern='/webjars/**'] with []
2022-10-23 22:22:55.225  WARN 6 --- [           main] o.s.s.c.a.web.builders.WebSecurity       : You are asking Spring Security to ignore Ant [pattern='/lms/**']. This is not recommended -- please use permitAll via HttpSecurity#authorizeHttpRequests instead.
2022-10-23 22:22:55.225  INFO 6 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Will secure Ant [pattern='/lms/**'] with []
2022-10-23 22:22:55.375  INFO 6 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Will not secure Or [Ant [pattern='/oauth/token'], Ant [pattern='/oauth/token_key'], Ant [pattern='/oauth/check_token']]
2022-10-23 22:22:55.402  INFO 6 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Will not secure org.springframework.security.oauth2.config.annotation.web.configuration.ResourceServerConfiguration$NotOAuthRequestMatcher@12dc702b
2022-10-23 22:22:55.414  INFO 6 --- [           main] o.s.s.web.DefaultSecurityFilterChain     : Will not secure any request
2022-10-23 22:22:55.592  INFO 6 --- [           main] pertySourcedRequestMappingHandlerMapping : Mapped URL path [/v2/api-docs] onto method [springfox.documentation.swagger2.web.Swagger2Controller#getDocumentation(String, HttpServletRequest)]
2022-10-23 22:22:56.080  INFO 6 --- [           main] org.quartz.impl.StdSchedulerFactory      : Using default implementation for ThreadExecutor
2022-10-23 22:22:56.125  INFO 6 --- [           main] org.quartz.core.SchedulerSignalerImpl    : Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
2022-10-23 22:22:56.125  INFO 6 --- [           main] org.quartz.core.QuartzScheduler          : Quartz Scheduler v.2.3.2 created.
2022-10-23 22:22:56.145  INFO 6 --- [           main] o.s.s.quartz.LocalDataSourceJobStore     : Using db table-based data access locking (synchronization).
2022-10-23 22:22:56.148  INFO 6 --- [           main] o.s.s.quartz.LocalDataSourceJobStore     : JobStoreCMT initialized.
2022-10-23 22:22:56.149  INFO 6 --- [           main] org.quartz.core.QuartzScheduler          : Scheduler meta-data: Quartz Scheduler (v2.3.2) 'statistics scheduler' with instanceId 'NON_CLUSTERED'
  Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally.
  NOT STARTED.
  Currently in standby mode.
  Number of jobs executed: 0
  Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 1 threads.
  Using job-store 'org.springframework.scheduling.quartz.LocalDataSourceJobStore' - which supports persistence. and is not clustered.
2022-10-23 22:22:56.149  INFO 6 --- [           main] org.quartz.impl.StdSchedulerFactory      : Quartz scheduler 'statistics scheduler' initialized from an externally provided properties instance.
2022-10-23 22:22:56.149  INFO 6 --- [           main] org.quartz.impl.StdSchedulerFactory      : Quartz scheduler version: 2.3.2
2022-10-23 22:22:56.149  INFO 6 --- [           main] org.quartz.core.QuartzScheduler          : JobFactory set to: org.springframework.scheduling.quartz.SpringBeanJobFactory@75507e68
2022-10-23 22:22:56.287  INFO 6 --- [           main] o.s.s.quartz.LocalDataSourceJobStore     : Freed 0 triggers from 'acquired' / 'blocked' state.
2022-10-23 22:22:56.292  INFO 6 --- [           main] o.s.s.quartz.LocalDataSourceJobStore     : Recovering 0 jobs that were in-progress at the time of the last shut-down.
2022-10-23 22:22:56.292  INFO 6 --- [           main] o.s.s.quartz.LocalDataSourceJobStore     : Recovery complete.
2022-10-23 22:22:56.294  INFO 6 --- [           main] o.s.s.quartz.LocalDataSourceJobStore     : Removed 0 'complete' triggers.
2022-10-23 22:22:56.296  INFO 6 --- [           main] o.s.s.quartz.LocalDataSourceJobStore     : Removed 0 stale fired job entries.
2022-10-23 22:22:56.333  INFO 6 --- [           main] org.quartz.core.QuartzScheduler          : Scheduler statistics scheduler_$_NON_CLUSTERED started.
2022-10-23 22:22:58.547  INFO 6 --- [           main] o.a.coyote.http11.Http11NioProtocol      : Starting ProtocolHandler ["http-nio-8080"]
2022-10-23 22:22:58.688  INFO 6 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2022-10-23 22:22:58.691  INFO 6 --- [           main] d.s.w.p.DocumentationPluginsBootstrapper : Context refreshed
2022-10-23 22:22:58.796  INFO 6 --- [           main] d.s.w.p.DocumentationPluginsBootstrapper : Found 1 custom documentation plugin(s)
2022-10-23 22:22:59.058  INFO 6 --- [           main] s.d.s.w.s.ApiListingReferenceScanner     : Scanning for api listing references
2022-10-23 22:23:00.162  INFO 6 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: regenerateApiKeyUsingPUT_1
2022-10-23 22:23:00.300  INFO 6 --- [           main] com.exadel.frs.FrsApplication            : Started FrsApplication in 37.34 seconds (JVM running for 41.66)
2022-10-23 22:23:27.978  INFO 6 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2022-10-23 22:23:27.979  INFO 6 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2022-10-23 22:23:27.982  INFO 6 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 3 ms
2022-10-23 22:23:28.583  INFO 6 --- [nio-8080-exec-1] o.s.s.o.p.token.store.JdbcTokenStore     : Failed to find access token
2022-10-23 22:28:29.768  INFO 6 --- [nio-8080-exec-4] o.s.s.o.p.token.store.JdbcTokenStore     : Failed to find access token

API:

Listening for transport dt_socket at address: 5005
  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::               (v2.5.13)
2022-10-23 22:28:55.563  INFO 7 --- [           main] com.exadel.frs.TrainServiceApplication   : Starting TrainServiceApplication v0.0.1-SNAPSHOT using Java 11.0.8 on 5cc114f3485a with PID 7 (/home/app.jar started by root in /)
2022-10-23 22:28:55.575  INFO 7 --- [kground-preinit] o.h.validator.internal.util.Version      : HV000001: Hibernate Validator 6.2.3.Final
2022-10-23 22:28:55.577  INFO 7 --- [           main] com.exadel.frs.TrainServiceApplication   : The following 1 profile is active: "dev"
2022-10-23 22:28:55.774  WARN 7 --- [           main] o.s.b.c.config.ConfigDataEnvironment     : Property 'spring.profiles' imported from location 'class path resource [application.yml]' is invalid and should be replaced with 'spring.config.activate.on-profile' [origin: class path resource [application.yml] from app.jar - 94:13]
2022-10-23 22:28:59.522  INFO 7 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2022-10-23 22:28:59.729  INFO 7 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 181 ms. Found 8 JPA repository interfaces.
2022-10-23 22:29:01.326  INFO 7 --- [           main] o.s.cloud.context.scope.GenericScope     : BeanFactory id=9776d44d-52e1-38dc-b671-bd86977f22bf
2022-10-23 22:29:02.348  INFO 7 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'cacheConfig' of type [com.exadel.frs.core.trainservice.config.CacheConfig$$EnhancerBySpringCGLIB$$89183a82] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2022-10-23 22:29:03.237  INFO 7 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2022-10-23 22:29:03.256  INFO 7 --- [           main] o.a.coyote.http11.Http11NioProtocol      : Initializing ProtocolHandler ["http-nio-8080"]
2022-10-23 22:29:03.256  INFO 7 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2022-10-23 22:29:03.256  INFO 7 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.62]
2022-10-23 22:29:03.426  INFO 7 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2022-10-23 22:29:03.426  INFO 7 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 7641 ms
2022-10-23 22:29:04.071  INFO 7 --- [           main] o.hibernate.jpa.internal.util.LogHelper  : HHH000204: Processing PersistenceUnitInfo [name: default]
2022-10-23 22:29:04.310  INFO 7 --- [           main] org.hibernate.Version                    : HHH000412: Hibernate ORM core version 5.4.33
2022-10-23 22:29:04.316  INFO 7 --- [           main] org.hibernate.cfg.Environment            : HHH000205: Loaded properties from resource hibernate.properties: {hibernate.bytecode.use_reflection_optimizer=false, hibernate.types.print.banner=false}
2022-10-23 22:29:04.911  INFO 7 --- [           main] o.hibernate.annotations.common.Version   : HCANN000001: Hibernate Commons Annotations {5.1.2.Final}
2022-10-23 22:29:05.940  INFO 7 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2022-10-23 22:29:06.220  INFO 7 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
2022-10-23 22:29:06.291  INFO 7 --- [           main] org.hibernate.dialect.Dialect            : HHH000400: Using dialect: org.hibernate.dialect.PostgreSQL10Dialect
2022-10-23 22:29:09.353  INFO 7 --- [           main] o.h.e.t.j.p.i.JtaPlatformInitiator       : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2022-10-23 22:29:09.392  INFO 7 --- [           main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
2022-10-23 22:29:16.855  INFO 7 --- [           main] o.s.b.a.e.web.EndpointLinksResolver      : Exposing 1 endpoint(s) beneath base path '/actuator'
2022-10-23 22:29:17.173  INFO 7 --- [           main] pertySourcedRequestMappingHandlerMapping : Mapped URL path [/v2/api-docs] onto method [springfox.documentation.swagger2.web.Swagger2Controller#getDocumentation(String, HttpServletRequest)]
2022-10-23 22:29:17.332  INFO 7 --- [           main] org.quartz.impl.StdSchedulerFactory      : Using default implementation for ThreadExecutor
2022-10-23 22:29:17.413  INFO 7 --- [           main] org.quartz.core.SchedulerSignalerImpl    : Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
2022-10-23 22:29:17.414  INFO 7 --- [           main] org.quartz.core.QuartzScheduler          : Quartz Scheduler v.2.3.2 created.
2022-10-23 22:29:17.415  INFO 7 --- [           main] org.quartz.simpl.RAMJobStore             : RAMJobStore initialized.
2022-10-23 22:29:17.420  INFO 7 --- [           main] org.quartz.core.QuartzScheduler          : Scheduler meta-data: Quartz Scheduler (v2.3.2) 'quartzScheduler' with instanceId 'NON_CLUSTERED'
  Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally.
  NOT STARTED.
  Currently in standby mode.
  Number of jobs executed: 0
  Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 10 threads.
  Using job-store 'org.quartz.simpl.RAMJobStore' - which does not support persistence. and is not clustered.
2022-10-23 22:29:17.420  INFO 7 --- [           main] org.quartz.impl.StdSchedulerFactory      : Quartz scheduler 'quartzScheduler' initialized from an externally provided properties instance.
2022-10-23 22:29:17.420  INFO 7 --- [           main] org.quartz.impl.StdSchedulerFactory      : Quartz scheduler version: 2.3.2
2022-10-23 22:29:17.420  INFO 7 --- [           main] org.quartz.core.QuartzScheduler          : JobFactory set to: org.springframework.scheduling.quartz.SpringBeanJobFactory@1ab268bd
2022-10-23 22:29:17.439  INFO 7 --- [           main] org.quartz.core.QuartzScheduler          : Scheduler quartzScheduler_$_NON_CLUSTERED started.
2022-10-23 22:29:18.505  INFO 7 --- [           main] o.a.coyote.http11.Http11NioProtocol      : Starting ProtocolHandler ["http-nio-8080"]
2022-10-23 22:29:18.531  INFO 7 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2022-10-23 22:29:18.536  INFO 7 --- [           main] d.s.w.p.DocumentationPluginsBootstrapper : Context refreshed
2022-10-23 22:29:18.617  INFO 7 --- [           main] d.s.w.p.DocumentationPluginsBootstrapper : Found 2 custom documentation plugin(s)
2022-10-23 22:29:18.881  INFO 7 --- [           main] s.d.s.w.s.ApiListingReferenceScanner     : Scanning for api listing references
2022-10-23 22:29:19.825  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeBase64UsingPOST_1
2022-10-23 22:29:19.836  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: downloadImgUsingGET_1
2022-10-23 22:29:20.003  INFO 7 --- [           main] s.d.s.w.s.ApiListingReferenceScanner     : Scanning for api listing references
2022-10-23 22:29:20.047  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: getConfigUsingGET_1
2022-10-23 22:29:20.049  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: getCheckDemoUsingGET_1
2022-10-23 22:29:20.078  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: detectUsingPOST_1
2022-10-23 22:29:20.086  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: detectBase64UsingPOST_1
2022-10-23 22:29:20.101  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: addEmbeddingUsingPOST_1
2022-10-23 22:29:20.104  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: addEmbeddingBase64UsingPOST_1
2022-10-23 22:29:20.106  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: deleteEmbeddingByIdUsingDELETE_1
2022-10-23 22:29:20.121  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: deleteEmbeddingsByIdUsingPOST_1
2022-10-23 22:29:20.123  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: downloadImgUsingGET_2
2022-10-23 22:29:20.128  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: listEmbeddingsUsingGET_1
2022-10-23 22:29:20.147  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeBase64UsingPOST_2
2022-10-23 22:29:20.160  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeFileUsingPOST_1
2022-10-23 22:29:20.162  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: removeAllSubjectEmbeddingsUsingDELETE_1
2022-10-23 22:29:20.163  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: migrateUsingPOST_1
2022-10-23 22:29:20.166  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: handleUsingGET_1
2022-10-23 22:29:20.180  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeUsingPOST_1
2022-10-23 22:29:20.183  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeBase64UsingPOST_3
2022-10-23 22:29:20.184  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: downloadImgUsingGET_3
2022-10-23 22:29:20.188  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: createSubjectUsingPOST_1
2022-10-23 22:29:20.190  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: deleteSubjectUsingDELETE_1
2022-10-23 22:29:20.192  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: deleteSubjectsUsingDELETE_1
2022-10-23 22:29:20.194  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: listSubjectsUsingGET_1
2022-10-23 22:29:20.196  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: renameSubjectUsingPUT_1
2022-10-23 22:29:20.211  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: verifyUsingPOST_1
2022-10-23 22:29:20.219  INFO 7 --- [           main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: verifyBase64UsingPOST_1
2022-10-23 22:29:20.265  INFO 7 --- [           main] com.exadel.frs.TrainServiceApplication   : Started TrainServiceApplication in 26.986 seconds (JVM running for 28.209)
2022-10-23 22:30:14.895  INFO 7 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2022-10-23 22:30:14.909  INFO 7 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2022-10-23 22:30:14.919  INFO 7 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 6 ms
Killed

And finally, docker container ls -a:


```root@compreface:/opt# docker container ls -a
CONTAINER ID   IMAGE                                 COMMAND                  CREATED          STATUS          PORTS                                   NAMES
9a8c1f9ea9cf   exadel/compreface-fe:1.1.0            "/docker-entrypoint.…"   15 minutes ago   Up 12 minutes   0.0.0.0:8000->80/tcp, :::8000->80/tcp   compreface-ui
3b8f7d9aef94   exadel/compreface-admin:1.1.0         "sh -c 'java $ADMIN_…"   16 minutes ago   Up 12 minutes                                           compreface-admin
5cc114f3485a   exadel/compreface-api:1.1.0           "sh -c 'java $API_JA…"   16 minutes ago   Up 2 minutes                                            compreface-api
73dac2befb22   exadel/compreface-postgres-db:1.1.0   "docker-entrypoint.s…"   17 minutes ago   Up 13 minutes   5432/tcp                                compreface-postgres-db
d5679af2275d   exadel/compreface-core:1.1.0          "uwsgi --ini uwsgi.i…"   17 minutes ago   Up 13 minutes   3000/tcp

from compreface.

atv2016 commented on May 22, 2024

This is the error.
Liquibase that initializes the database tries to acquire lock but fails. It happens sometimes if you started the system and before all initialization is done, it stops.
The solution here is just to clear the database, so it will initiate it again.
Just wait enough time until it's done, it usually it takes about 30 seconds

How does one clear the database ?

from compreface.

vpraveenmac commented on May 22, 2024

This is the error.
Liquibase that initializes the database tries to acquire lock but fails. It happens sometimes if you started the system and before all initialization is done, it stops.
The solution here is just to clear the database, so it will initiate it again.
Just wait enough time until it's done, it usually it takes about 30 seconds

How does one clear the database ?

i cleared the DB by deleting the content of the /var/lib/docker/volumes/compreface_110_postgres-data/_data directory. you will lose all the apps//users/training data etc

from compreface.

Error 502 bad gateway about compreface HOT 22 OPEN

Comments (22)

Related Issues (20)

Recommend Projects

React

Vue.js

Typescript

TensorFlow

Django

Laravel

D3

Recommend Topics

javascript

web

server

Machine learning

Visualization

Game

Recommend Org

Facebook

Microsoft

Google

Alibaba

D3

Tencent