lenna.jpg on repeat

Open

#1,085 opened on Jun 9, 2023 1 comment 0 reactions 0 assignees View on GitHub

Dominant language: Java
Stars: 8.3k
Forks: 1.2k
PR merge metrics: No merged PRs in 30d

Description

**Describe the bug**

CompreFace is slowly using more and more RAM. I'm not sure if I need to configure CompreFace to be local somehow.

**To Reproduce**

Steps to reproduce the behavior:

These messages keep repeating in the logs:

`{"severity": "DEBUG", "message": "Found: BoundingBoxDTO(x_min=173, y_min=158, x_max=386, y_max=417, probability=0.9265303015708923, _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": "127.0.0.1"}, "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": "127.0.0.1"}, "logger": "src.services.flask_.log_response", "module": "log_response", "traceback": null, "build_version": "dev"}`

**Expected behavior**

I would expect memory to not be slowly increasing while idle.

**Screenshots**

If applicable, add screenshots to help explain your problem.

**Desktop (please complete the following information):**

- OS: Unraid
- Browser FireFox
- Version 1.1.0

**Logs**

Run those commands and attach result to the ticket:

'CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
0ac12110e576 exadel/compreface "/usr/bin/supervisord" 23 minutes ago Up 15 minutes 3000/tcp, 0.0.0.0:8800->80/tcp' CompreFace

Docker Logs:

ErrorWarningSystemArrayLogin

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 0x5608c60f1b00
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 ***
Starting compreface-postgres-db
2023-06-09 04:57:28,599 INFO spawned: 'compreface-postgres-db' with pid 43
2023-06-09 04:57:28,599 INFO success: compreface-postgres-db entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
compreface-postgres-db: started
2023-06-09 11:57:28.635 UTC [43] LOG: starting PostgreSQL 13.8 (Debian 13.8-1.pgdg110+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2023-06-09 11:57:28.636 UTC [43] LOG: listening on IPv4 address "127.0.0.1", port 5432
2023-06-09 11:57:28.636 UTC [43] LOG: could not bind IPv6 address "::1": Cannot assign requested address
2023-06-09 11:57:28.636 UTC [43] HINT: Is another postmaster already running on port 5432? If not, wait a few seconds and retry.
2023-06-09 11:57:28.642 UTC [43] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2023-06-09 11:57:28.657 UTC [45] LOG: database system was shut down at 2023-06-09 11:57:26 UTC
2023-06-09 11:57:28.665 UTC [43] LOG: database system is ready to accept connections
{"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 1 seconds on interpreter 0x5608c60f1b00 pid: 8 (default app)
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI master process (pid: 8)
spawned uWSGI worker 1 (pid: 54, cores: 1)
spawned uWSGI worker 2 (pid: 55, cores: 1)
Starting compreface-admin
2023-06-09 04:57:38,715 INFO spawned: 'compreface-admin' with pid 57
2023-06-09 04:57:38,715 INFO success: compreface-admin entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
compreface-admin: started

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

2023-06-09 04:57:39.550 INFO 57 --- [kground-preinit] o.h.validator.internal.util.Version : HV000001: Hibernate Validator 6.2.3.Final
2023-06-09 04:57:39.564 INFO 57 --- [ main] com.exadel.frs.FrsApplication : Starting FrsApplication v0.0.1-SNAPSHOT using Java 11.0.16 on 0ac12110e576 with PID 57 (/app/admin/app.jar started by root in /app/admin)
2023-06-09 04:57:39.564 DEBUG 57 --- [ main] com.exadel.frs.FrsApplication : Running with Spring Boot v2.5.13, Spring v5.3.19
2023-06-09 04:57:39.565 INFO 57 --- [ main] com.exadel.frs.FrsApplication : The following 1 profile is active: "dev"
2023-06-09 04:57:40.521 INFO 57 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2023-06-09 04:57:40.596 INFO 57 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 69 ms. Found 11 JPA repository interfaces.
2023-06-09 04:57:40.801 INFO 57 --- [ main] o.s.cloud.context.scope.GenericScope : BeanFactory id=87eecb33-b947-31b8-bbb7-8d063df92185
2023-06-09 04:57:41.319 INFO 57 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8081 (http)
2023-06-09 04:57:41.325 INFO 57 --- [ main] o.a.coyote.http11.Http11NioProtocol : Initializing ProtocolHandler ["http-nio-8081"]
2023-06-09 04:57:41.326 INFO 57 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2023-06-09 04:57:41.326 INFO 57 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.62]
2023-06-09 04:57:41.378 INFO 57 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2023-06-09 04:57:41.378 INFO 57 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1767 ms
2023-06-09 04:57:41.740 INFO 57 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Starting...
2023-06-09 04:57:41.933 INFO 57 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Start completed.
2023-06-09 04:57:42.045 INFO 57 --- [ main] liquibase.database : Set default schema name to public
2023-06-09 04:57:42.120 INFO 57 --- [ main] liquibase.lockservice : Successfully acquired change log lock
2023-06-09 04:57:42.419 INFO 57 --- [ main] liquibase.changelog : Reading from public.databasechangelog
2023-06-09 04:57:42.520 INFO 57 --- [ main] liquibase.lockservice : Successfully released change log lock
2023-06-09 11:57:42.872 UTC [105] compreface@frs WARNING: there is no transaction in progress
2023-06-09 04:57:42.928 INFO 57 --- [ main] o.hibernate.jpa.internal.util.LogHelper : HHH000204: Processing PersistenceUnitInfo [name: default]
2023-06-09 04:57:42.982 INFO 57 --- [ main] org.hibernate.Version : HHH000412: Hibernate ORM core version 5.4.33
2023-06-09 04:57:43.065 INFO 57 --- [ main] o.hibernate.annotations.common.Version : HCANN000001: Hibernate Commons Annotations {5.1.2.Final}
2023-06-09 04:57:43.137 INFO 57 --- [ main] org.hibernate.dialect.Dialect : HHH000400: Using dialect: org.hibernate.dialect.PostgreSQL10Dialect
2023-06-09 04:57:43.177 INFO 57 --- [ 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/
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<

2023-06-09 04:57:43.763 INFO 57 --- [ main] o.h.e.t.j.p.i.JtaPlatformInitiator : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2023-06-09 04:57:43.769 INFO 57 --- [ main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
2023-06-09 04:57:45.050 INFO 57 --- [ main] o.s.b.a.e.web.EndpointLinksResolver : Exposing 1 endpoint(s) beneath base path '/actuator'
2023-06-09 04:57:45.526 WARN 57 --- [ 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.
2023-06-09 04:57:45.527 INFO 57 --- [ main] o.s.s.web.DefaultSecurityFilterChain : Will secure Ant [pattern='/v2/api-docs'] with []
2023-06-09 04:57:45.527 WARN 57 --- [ 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.
2023-06-09 04:57:45.527 INFO 57 --- [ main] o.s.s.web.DefaultSecurityFilterChain : Will secure Ant [pattern='/configuration/ui'] with []
2023-06-09 04:57:45.527 WARN 57 --- [ 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.
2023-06-09 04:57:45.527 INFO 57 --- [ main] o.s.s.web.DefaultSecurityFilterChain : Will secure Ant [pattern='/swagger-resources/**'] with []
2023-06-09 04:57:45.527 WARN 57 --- [ 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.
2023-06-09 04:57:45.527 INFO 57 --- [ main] o.s.s.web.DefaultSecurityFilterChain : Will secure Ant [pattern='/configuration/**'] with []

09 04:57:45.527 WARN 57 --- [ 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.
2023-06-09 04:57:45.527 INFO 57 --- [ main] o.s.s.web.DefaultSecurityFilterChain : Will secure Ant [pattern='/swagger-ui**'] with []
2023-06-09 04:57:45.527 WARN 57 --- [ 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.
2023-06-09 04:57:45.527 INFO 57 --- [ main] o.s.s.web.DefaultSecurityFilterChain : Will secure Ant [pattern='/webjars/**'] with []
2023-06-09 04:57:45.527 WARN 57 --- [ 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.
2023-06-09 04:57:45.527 INFO 57 --- [ main] o.s.s.web.DefaultSecurityFilterChain : Will secure Ant [pattern='/lms/**'] with []
2023-06-09 04:57:45.554 INFO 57 --- [ main] o.s.s.web.DefaultSecurityFilterChain : Will not secure Or [Ant [pattern='/oauth/token'], Ant [pattern='/oauth/token_key'], Ant [pattern='/oauth/check_token']]
2023-06-09 04:57:45.564 INFO 57 --- [ main] o.s.s.web.DefaultSecurityFilterChain : Will not secure org.springframework.security.oauth2.config.annotation.web.configuration.ResourceServerConfiguration$NotOAuthRequestMatcher@2d3111a1
2023-06-09 04:57:45.566 INFO 57 --- [ main] o.s.s.web.DefaultSecurityFilterChain : Will not secure any request
2023-06-09 04:57:45.600 INFO 57 --- [ main] pertySourcedRequestMappingHandlerMapping : Mapped URL path [/v2/api-docs] onto method [springfox.documentation.swagger2.web.Swagger2Controller#getDocumentation(String, HttpServletRequest)]
2023-06-09 04:57:45.671 INFO 57 --- [ main] org.quartz.impl.StdSchedulerFactory : Using default implementation for ThreadExecutor
2023-06-09 04:57:45.682 INFO 57 --- [ main] org.quartz.core.SchedulerSignalerImpl : Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
2023-06-09 04:57:45.682 INFO 57 --- [ main] org.quartz.core.QuartzScheduler : Quartz Scheduler v.2.3.2 created.
2023-06-09 04:57:45.684 INFO 57 --- [ main] o.s.s.quartz.LocalDataSourceJobStore : Using db table-based data access locking (synchronization).
2023-06-09 04:57:45.686 INFO 57 --- [ main] o.s.s.quartz.LocalDataSourceJobStore : JobStoreCMT initialized.
2023-06-09 04:57:45.687 INFO 57 --- [ 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.

2023-06-09 04:57:45.687 INFO 57 --- [ main] org.quartz.impl.StdSchedulerFactory : Quartz scheduler 'statistics scheduler' initialized from an externally provided properties instance.
2023-06-09 04:57:45.687 INFO 57 --- [ main] org.quartz.impl.StdSchedulerFactory : Quartz scheduler version: 2.3.2
2023-06-09 04:57:45.687 INFO 57 --- [ main] org.quartz.core.QuartzScheduler : JobFactory set to: org.springframework.scheduling.quartz.SpringBeanJobFactory@727f36dd
2023-06-09 04:57:45.734 INFO 57 --- [ main] o.s.s.quartz.LocalDataSourceJobStore : Freed 0 triggers from 'acquired' / 'blocked' state.
2023-06-09 04:57:45.738 INFO 57 --- [ main] o.s.s.quartz.LocalDataSourceJobStore : Recovering 0 jobs that were in-progress at the time of the last shut-down.
2023-06-09 04:57:45.738 INFO 57 --- [ main] o.s.s.quartz.LocalDataSourceJobStore : Recovery complete.
2023-06-09 04:57:45.739 INFO 57 --- [ main] o.s.s.quartz.LocalDataSourceJobStore : Removed 0 'complete' triggers.
2023-06-09 04:57:45.739 INFO 57 --- [ main] o.s.s.quartz.LocalDataSourceJobStore : Removed 0 stale fired job entries.
2023-06-09 04:57:45.742 INFO 57 --- [ main] org.quartz.core.QuartzScheduler : Scheduler statistics scheduler_$_NON_CLUSTERED started.
2023-06-09 04:57:46.243 INFO 57 --- [ main] o.a.coyote.http11.Http11NioProtocol : Starting ProtocolHandler ["http-nio-8081"]
2023-06-09 04:57:46.255 INFO 57 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8081 (http) with context path ''
2023-06-09 04:57:46.257 INFO 57 --- [ main] d.s.w.p.DocumentationPluginsBootstrapper : Context refreshed
2023-06-09 04:57:46.274 INFO 57 --- [ main] d.s.w.p.DocumentationPluginsBootstrapper : Found 1 custom documentation plugin(s)
2023-06-09 04:57:46.330 INFO 57 --- [ main] s.d.s.w.s.ApiListingReferenceScanner : Scanning for api listing references
2023-06-09 04:57:46.481 INFO 57 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: regenerateApiKeyUsingPUT_1
2023-06-09 04:57:46.538 INFO 57 --- [ main] com.exadel.frs.FrsApplication : Started FrsApplication in 7.508 seconds (JVM running for 7.818)
Starting compreface-api
2023-06-09 04:57:48,819 INFO spawned: 'compreface-api' with pid 134
2023-06-09 04:57:48,819 INFO success: compreface-api entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
compreface-api: started

2023-06-09 04:57:49.678 INFO 134 --- [kground-preinit] o.h.validator.internal.util.Version : HV000001: Hibernate Validator 6.2.3.Final
2023-06-09 04:57:49.682 INFO 134 --- [ main] com.exadel.frs.TrainServiceApplication : Starting TrainServiceApplication v0.0.1-SNAPSHOT using Java 11.0.16 on 0ac12110e576 with PID 134 (/app/api/app.jar started by root in /app/api)
2023-06-09 04:57:49.682 INFO 134 --- [ main] com.exadel.frs.TrainServiceApplication : The following 1 profile is active: "dev"
2023-06-09 04:57:49.722 WARN 134 --- [ 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]
2023-06-09 04:57:50.405 INFO 134 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2023-06-09 04:57:50.453 INFO 134 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 42 ms. Found 8 JPA repository interfaces.
2023-06-09 04:57:50.866 INFO 134 --- [ main] o.s.cloud.context.scope.GenericScope : BeanFactory id=9776d44d-52e1-38dc-b671-bd86977f22bf
2023-06-09 04:57:51.161 INFO 134 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'cacheConfig' of type [com.exadel.frs.core.trainservice.config.CacheConfig$$EnhancerBySpringCGLIB$$d96d8145] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2023-06-09 04:57:51.428 INFO 134 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http)
2023-06-09 04:57:51.435 INFO 134 --- [ main] o.a.coyote.http11.Http11NioProtocol : Initializing ProtocolHandler ["http-nio-8080"]
2023-06-09 04:57:51.436 INFO 134 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2023-06-09 04:57:51.436 INFO 134 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.62]
2023-06-09 04:57:51.491 INFO 134 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2023-06-09 04:57:51.492 INFO 134 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1769 ms
2023-06-09 04:57:51.848 INFO 134 --- [ main] o.hibernate.jpa.internal.util.LogHelper : HHH000204: Processing PersistenceUnitInfo [name: default]
2023-06-09 04:57:51.921 INFO 134 --- [ main] org.hibernate.Version : HHH000412: Hibernate ORM core version 5.4.33
2023-06-09 04:57:51.922 INFO 134 --- [ main] org.hibernate.cfg.Environment : HHH000205: Loaded properties from resource hibernate.properties: {hibernate.bytecode.use_reflection_optimizer=false, hibernate.types.print.banner=false}
2023-06-09 04:57:52.041 INFO 134 --- [ main] o.hibernate.annotations.common.Version : HCANN000001: Hibernate Commons Annotations {5.1.2.Final}
2023-06-09 04:57:52.353 INFO 134 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Starting...
2023-06-09 04:57:52.524 INFO 134 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Start completed.
2023-06-09 04:57:52.542 INFO 134 --- [ main] org.hibernate.dialect.Dialect : HHH000400: Using dialect: org.hibernate.dialect.PostgreSQL10Dialect
2023-06-09 04:57:53.283 INFO 134 --- [ main] o.h.e.t.j.p.i.JtaPlatformInitiator : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2023-06-09 04:57:53.291 INFO 134 --- [ main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
2023-06-09 04:57:55.561 INFO 134 --- [ main] o.s.b.a.e.web.EndpointLinksResolver : Exposing 1 endpoint(s) beneath base path '/actuator'
2023-06-09 04:57:55.679 INFO 134 --- [ main] pertySourcedRequestMappingHandlerMapping : Mapped URL path [/v2/api-docs] onto method [springfox.documentation.swagger2.web.Swagger2Controller#getDocumentation(String, HttpServletRequest)]
2023-06-09 04:57:55.743 INFO 134 --- [ main] org.quartz.impl.StdSchedulerFactory : Using default implementation for ThreadExecutor
2023-06-09 04:57:55.754 INFO 134 --- [ main] org.quartz.core.SchedulerSignalerImpl : Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
2023-06-09 04:57:55.754 INFO 134 --- [ main] org.quartz.core.QuartzScheduler : Quartz Scheduler v.2.3.2 created.
2023-06-09 04:57:55.755 INFO 134 --- [ main] org.quartz.simpl.RAMJobStore : RAMJobStore initialized.
2023-06-09 04:57:55.755 INFO 134 --- [ 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.

2023-06-09 04:57:55.756 INFO 134 --- [ main] org.quartz.impl.StdSchedulerFactory : Quartz scheduler 'quartzScheduler' initialized from an externally provided properties instance.
2023-06-09 04:57:55.756 INFO 134 --- [ main] org.quartz.impl.StdSchedulerFactory : Quartz scheduler version: 2.3.2
2023-06-09 04:57:55.756 INFO 134 --- [ main] org.quartz.core.QuartzScheduler : JobFactory set to: org.springframework.scheduling.quartz.SpringBeanJobFactory@37d6dddc
2023-06-09 04:57:55.760 INFO 134 --- [ main] org.quartz.core.QuartzScheduler : Scheduler quartzScheduler_$_NON_CLUSTERED started.
2023-06-09 04:57:56.192 INFO 134 --- [ main] o.a.coyote.http11.Http11NioProtocol : Starting ProtocolHandler ["http-nio-8080"]
2023-06-09 04:57:56.201 INFO 134 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8080 (http) with context path ''
2023-06-09 04:57:56.202 INFO 134 --- [ main] d.s.w.p.DocumentationPluginsBootstrapper : Context refreshed
2023-06-09 04:57:56.218 INFO 134 --- [ main] d.s.w.p.DocumentationPluginsBootstrapper : Found 2 custom documentation plugin(s)
2023-06-09 04:57:56.280 INFO 134 --- [ main] s.d.s.w.s.ApiListingReferenceScanner : Scanning for api listing references
2023-06-09 04:57:56.457 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeBase64UsingPOST_1
2023-06-09 04:57:56.459 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: downloadImgUsingGET_1
2023-06-09 04:57:56.514 INFO 134 --- [ main] s.d.s.w.s.ApiListingReferenceScanner : Scanning for api listing references
2023-06-09 04:57:56.531 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: getConfigUsingGET_1
2023-06-09 04:57:56.533 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: getCheckDemoUsingGET_1
2023-06-09 04:57:56.542 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: detectUsingPOST_1
2023-06-09 04:57:56.545 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: detectBase64UsingPOST_1
2023-06-09 04:57:56.548 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: addEmbeddingUsingPOST_1
2023-06-09 04:57:56.552 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: addEmbeddingBase64UsingPOST_1
2023-06-09 04:57:56.554 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: deleteEmbeddingByIdUsingDELETE_1
2023-06-09 04:57:56.557 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: deleteEmbeddingsByIdUsingPOST_1
2023-06-09 04:57:56.559 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: downloadImgUsingGET_2
2023-06-09 04:57:56.564 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: listEmbeddingsUsingGET_1
2023-06-09 04:57:56.574 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeBase64UsingPOST_2
2023-06-09 04:57:56.576 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeFileUsingPOST_1
2023-06-09 04:57:56.578 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: removeAllSubjectEmbeddingsUsingDELETE_1
2023-06-09 04:57:56.580 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: migrateUsingPOST_1
2023-06-09 04:57:56.584 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: handleUsingGET_1
2023-06-09 04:57:56.592 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeUsingPOST_1
2023-06-09 04:57:56.595 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeBase64UsingPOST_3
2023-06-09 04:57:56.598 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: downloadImgUsingGET_3
2023-06-09 04:57:56.601 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: createSubjectUsingPOST_1
2023-06-09 04:57:56.603 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: deleteSubjectUsingDELETE_1
2023-06-09 04:57:56.604 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: deleteSubjectsUsingDELETE_1
2023-06-09 04:57:56.605 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: listSubjectsUsingGET_1
2023-06-09 04:57:56.607 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: renameSubjectUsingPUT_1
2023-06-09 04:57:56.618 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: verifyUsingPOST_1
2023-06-09 04:57:56.622 INFO 134 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: verifyBase64UsingPOST_1
2023-06-09 04:57:56.649 INFO 134 --- [ main] com.exadel.frs.TrainServiceApplication : Started TrainServiceApplication in 7.504 seconds (JVM running for 7.825)
Starting compreface-fe
2023-06-09 04:57:58,923 INFO spawned: 'compreface-fe' with pid 220
2023-06-09 04:57:58,923 INFO success: compreface-fe entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
compreface-fe: started
2023-06-09 04:57:58,933 INFO exited: startup (exit status 0; expected)
2023-06-09 04:58:00.037 INFO 57 --- [nio-8081-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring DispatcherServlet 'dispatcherServlet'
2023-06-09 04:58:00.038 INFO 57 --- [nio-8081-exec-1] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet'
2023-06-09 04:58:00.039 INFO 57 --- [nio-8081-exec-1] o.s.web.servlet.DispatcherServlet : Completed initialization in 1 ms
2023-06-09 04:58:00.286 INFO 57 --- [nio-8081-exec-1] o.s.s.o.p.token.store.JdbcTokenStore : Failed to find access token
xxx.xxx.x.xx - CommonClientId [09/Jun/2023:04:58:00 -0700] "POST /admin/oauth/token?grant_type=refresh_token&scope=all HTTP/1.1" 200 0 "http://xxx.xxx.x.xx:8800/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/116.0"
xxx.xxx.x.xx - - [09/Jun/2023:04:58:11 -0700] "GET /favicon.ico HTTP/1.1" 200 10313 "http://xxx.xxx.x.xx:8800/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/116.0"
xxx.xxx.x.xx - - [09/Jun/2023:04:58:11 -0700] "GET /admin/user/me HTTP/1.1" 200 137 "http://xxx.xxx.x.xx:8800/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/116.0"
xxx.xxx.x.xx - - [09/Jun/2023:04:58:11 -0700] "GET /admin/user/roles HTTP/1.1" 200 151 "http://xxx.xxx.x.xx:8800/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/116.0"
2023-06-09 04:58:11.952 INFO 134 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring DispatcherServlet 'dispatcherServlet'
2023-06-09 04:58:11.952 INFO 134 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet'
2023-06-09 04:58:11.954 INFO 134 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Completed initialization in 1 ms
xxx.xxx.x.xx - - [09/Jun/2023:04:58:11 -0700] "GET /admin/apps HTTP/1.1" 200 209 "http://xxx.xxx.x.xx:8800/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/116.0"
xxx.xxx.x.xx - - [09/Jun/2023:04:58:12 -0700] "GET /api/v1/config HTTP/1.1" 200 83 "http://xxx.xxx.x.xx:8800/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/116.0"
2023-06-09 04:58:24.498271: 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.9265303015708923, _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": "127.0.0.1"}, "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": "127.0.0.1"}, "logger": "src.services.flask_.log_response", "module": "log_response", "traceback": null, "build_version": "dev"}
2023-06-09 04:58:27.169 INFO 134 --- [nio-8080-exec-2] org.nd4j.linalg.factory.Nd4jBackend : Loaded [CpuBackend] backend
2023-06-09 04:58:27.533 INFO 134 --- [nio-8080-exec-2] org.nd4j.nativeblas.NativeOpsHolder : Number of threads used for linear algebra: 8
2023-06-09 04:58:27.533 WARN 134 --- [nio-8080-exec-2] o.n.l.cpu.nativecpu.CpuNDArrayFactory : *********************************** CPU Feature Check Warning ***********************************
2023-06-09 04:58:27.534 WARN 134 --- [nio-8080-exec-2] o.n.l.cpu.nativecpu.CpuNDArrayFactory : Warning: Initializing ND4J with Generic x86 binary on a CPU with AVX/AVX2 support
2023-06-09 04:58:27.534 WARN 134 --- [nio-8080-exec-2] o.n.l.cpu.nativecpu.CpuNDArrayFactory : Using ND4J with AVX/AVX2 will improve performance. See deeplearning4j.org/cpu for more details
2023-06-09 04:58:27.534 WARN 134 --- [nio-8080-exec-2] o.n.l.cpu.nativecpu.CpuNDArrayFactory : Or set environment variable ND4J_IGNORE_AVX=true to suppress this warning
2023-06-09 04:58:27.534 WARN 134 --- [nio-8080-exec-2] o.n.l.cpu.nativecpu.CpuNDArrayFactory : *************************************************************************************************
2023-06-09 04:58:27.538 INFO 134 --- [nio-8080-exec-2] org.nd4j.nativeblas.Nd4jBlas : Number of threads used for OpenMP BLAS: 8
2023-06-09 04:58:27.541 INFO 134 --- [nio-8080-exec-2] o.n.l.a.o.e.DefaultOpExecutioner : Backend used: [CPU]; OS: [Linux]
2023-06-09 04:58:27.541 INFO 134 --- [nio-8080-exec-2] o.n.l.a.o.e.DefaultOpExecutioner : Cores: [16]; Memory: [4.0GB];
2023-06-09 04:58:27.541 INFO 134 --- [nio-8080-exec-2] o.n.l.a.o.e.DefaultOpExecutioner : Blas vendor: [OPENBLAS]
2023-06-09 04:58:27.633 INFO 134 --- [PG-JDBC I/O (2)] c.e.f.c.t.s.NotificationReceiverService : /channels3/ channel name: face_collection_update_msg payload {
"cacheAction" : "UPDATE",
"apiKey" : "9d2a8fc4-12d1-4ee7-8473-13e3d1195499",
"uuid" : "42558ea0-3858-437f-aba2-cfe6b4e82d77"
}
{"severity": "INFO", "message": "200 OK", "request": {"method": "GET", "path": "/status", "filename": "", "api_key": "", "remote_addr": "127.0.0.1"}, "logger": "src.services.flask_.log_response", "module": "log_response", "traceback": null, "build_version": "dev"}
xxx.xxx.x.xx - - [09/Jun/2023:04:58:27 -0700] "POST /api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8 HTTP/1.1" 200 257 "-" "axios/0.27.2"
2023-06-09 04:58:32,970 WARN received SIGTERM indicating exit request
2023-06-09 04:58:32,970 INFO waiting for compreface-postgres-db, compreface-admin, compreface-api, compreface-core, compreface-fe to die
2023-06-09 04:58:32,971 INFO stopped: compreface-fe (exit status 0)
SIGINT/SIGQUIT received...killing workers...
worker 1 buried after 1 seconds
worker 2 buried after 1 seconds
goodbye to uWSGI.
2023-06-09 04:58:34,990 INFO stopped: compreface-core (exit status 0)
2023-06-09 04:58:34.993 INFO 134 --- [ionShutdownHook] org.quartz.core.QuartzScheduler : Scheduler quartzScheduler_$_NON_CLUSTERED paused.
2023-06-09 04:58:35.000 INFO 134 --- [ionShutdownHook] org.quartz.core.QuartzScheduler : Scheduler quartzScheduler_$_NON_CLUSTERED shutting down.
2023-06-09 04:58:35.000 INFO 134 --- [ionShutdownHook] org.quartz.core.QuartzScheduler : Scheduler quartzScheduler_$_NON_CLUSTERED paused.
2023-06-09 04:58:35.000 INFO 134 --- [ionShutdownHook] org.quartz.core.QuartzScheduler : Scheduler quartzScheduler_$_NON_CLUSTERED shutdown complete.
2023-06-09 04:58:35.000 INFO 134 --- [ionShutdownHook] o.s.s.quartz.SchedulerFactoryBean : Shutting down Quartz Scheduler
2023-06-09 04:58:35.006 INFO 134 --- [ionShutdownHook] j.LocalContainerEntityManagerFactoryBean : Closing JPA EntityManagerFactory for persistence unit 'default'
2023-06-09 04:58:35.006 INFO 134 --- [ionShutdownHook] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Shutdown initiated...
2023-06-09 04:58:35.009 INFO 134 --- [ionShutdownHook] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Shutdown completed.
2023-06-09 04:58:35,383 INFO stopped: compreface-api (exit status 143)
2023-06-09 04:58:35.386 INFO 57 --- [ionShutdownHook] org.quartz.core.QuartzScheduler : Scheduler statistics scheduler_$_NON_CLUSTERED paused.
2023-06-09 04:58:35.394 INFO 57 --- [ionShutdownHook] org.quartz.core.QuartzScheduler : Scheduler statistics scheduler_$_NON_CLUSTERED shutting down.
2023-06-09 04:58:35.395 INFO 57 --- [ionShutdownHook] org.quartz.core.QuartzScheduler : Scheduler statistics scheduler_$_NON_CLUSTERED paused.
2023-06-09 04:58:35.395 INFO 57 --- [ionShutdownHook] org.quartz.core.QuartzScheduler : Scheduler statistics scheduler_$_NON_CLUSTERED shutdown complete.
2023-06-09 04:58:35.395 INFO 57 --- [ionShutdownHook] o.s.s.quartz.SchedulerFactoryBean : Shutting down Quartz Scheduler
2023-06-09 04:58:35.402 INFO 57 --- [ionShutdownHook] j.LocalContainerEntityManagerFactoryBean : Closing JPA EntityManagerFactory for persistence unit 'default'
2023-06-09 04:58:35.403 INFO 57 --- [ionShutdownHook] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Shutdown initiated...
2023-06-09 04:58:35.406 INFO 57 --- [ionShutdownHook] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Shutdown completed.
2023-06-09 04:58:35,450 INFO stopped: compreface-admin (exit status 143)
2023-06-09 04:58:36,450 INFO waiting for compreface-postgres-db to die
2023-06-09 11:58:36.450 UTC [43] LOG: received fast shutdown request
2023-06-09 11:58:36.455 UTC [43] LOG: aborting any active transactions
2023-06-09 11:58:36.456 UTC [43] LOG: background worker "logical replication launcher" (PID 51) exited with exit code 1
2023-06-09 11:58:36.456 UTC [46] LOG: shutting down
2023-06-09 11:58:36.695 UTC [43] LOG: database system is shut down
2023-06-09 04:58:36,696 INFO stopped: compreface-postgres-db (exit status 0)
/usr/lib/python3/dist-packages/supervisor/options.py:474: UserWarning: Supervisord is running as root and it is searching for its configuration file in default locations (including its current working directory); you probably want to specify a "-c" argument specifying an absolute path to a configuration file for improved security.
self.warnings.warn(
2023-06-09 04:58:37,238 CRIT Supervisor is running as root. Privileges were not dropped because no user is specified in the config file. If you intend to run as root, you can set user=root in the config file to avoid this message.
2023-06-09 04:58:37,238 INFO Included extra file "/etc/supervisor/conf.d/supervisord.conf" during parsing
2023-06-09 04:58:37,240 INFO RPC interface 'supervisor' initialized
2023-06-09 04:58:37,240 CRIT Server 'unix_http_server' running without any HTTP authentication checking
2023-06-09 04:58:37,240 INFO supervisord started with pid 1
2023-06-09 04:58:38,242 INFO spawned: 'startup' with pid 7
2023-06-09 04:58:38,243 INFO spawned: 'compreface-core' with pid 8
[uWSGI] getting INI configuration from uwsgi.ini
*** Starting uWSGI 2.0.19 (64bit) on [Fri Jun 9 04:58:38 2023] ***
compiled with version: 10.2.1 20210110 on 07 October 2022 08:24:18
os: Linux-5.10.28-Unraid #1 SMP Wed Apr 7 08:23:18 PDT 2021
nodename: 0ac12110e576
machine: x86_64
clock source: unix
detected number of CPU cores: 16
current working directory: /app/ml
detected binary path: /usr/local/bin/uwsgi
!!! no internal routing support, rebuild with pcre support !!!
2023-06-09 04:58:38,246 INFO success: startup entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
2023-06-09 04:58:38,246 INFO success: compreface-core entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
setgid() to 33
setuid() to 33
your processes number limit is 256119
your memory page size is 4096 bytes
detected max file descriptor number: 40960
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 0x56551a427b00
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 ***
Starting compreface-postgres-db
2023-06-09 04:58:38,459 INFO spawned: 'compreface-postgres-db' with pid 43
2023-06-09 04:58:38,459 INFO success: compreface-postgres-db entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
compreface-postgres-db: started
2023-06-09 11:58:38.489 UTC [43] LOG: starting PostgreSQL 13.8 (Debian 13.8-1.pgdg110+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2023-06-09 11:58:38.489 UTC [43] LOG: listening on IPv4 address "127.0.0.1", port 5432
2023-06-09 11:58:38.489 UTC [43] LOG: could not bind IPv6 address "::1": Cannot assign requested address
2023-06-09 11:58:38.489 UTC [43] HINT: Is another postmaster already running on port 5432? If not, wait a few seconds and retry.
2023-06-09 11:58:38.496 UTC [43] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2023-06-09 11:58:38.504 UTC [45] LOG: database system was shut down at 2023-06-09 11:58:36 UTC
2023-06-09 11:58:38.511 UTC [43] LOG: database system is ready to accept connections
{"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 1 seconds on interpreter 0x56551a427b00 pid: 8 (default app)
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI master process (pid: 8)
spawned uWSGI worker 1 (pid: 54, cores: 1)
spawned uWSGI worker 2 (pid: 55, cores: 1)
Starting compreface-admin
2023-06-09 04:58:48,573 INFO spawned: 'compreface-admin' with pid 57
2023-06-09 04:58:48,573 INFO success: compreface-admin entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
compreface-admin: started

2023-06-09 04:58:49.511 INFO 57 --- [kground-preinit] o.h.validator.internal.util.Version : HV000001: Hibernate Validator 6.2.3.Final
2023-06-09 04:58:49.544 INFO 57 --- [ main] com.exadel.frs.FrsApplication : Starting FrsApplication v0.0.1-SNAPSHOT using Java 11.0.16 on 0ac12110e576 with PID 57 (/app/admin/app.jar started by root in /app/admin)
2023-06-09 04:58:49.545 DEBUG 57 --- [ main] com.exadel.frs.FrsApplication : Running with Spring Boot v2.5.13, Spring v5.3.19
2023-06-09 04:58:49.545 INFO 57 --- [ main] com.exadel.frs.FrsApplication : The following 1 profile is active: "dev"
2023-06-09 04:58:50.463 INFO 57 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2023-06-09 04:58:50.534 INFO 57 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 65 ms. Found 11 JPA repository interfaces.
2023-06-09 04:58:50.463 INFO 57 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2023-06-09 04:58:50.534 INFO 57 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 65 ms. Found 11 JPA repository interfaces.
2023-06-09 04:58:50.740 INFO 57 --- [ main] o.s.cloud.context.scope.GenericScope : BeanFactory id=87eecb33-b947-31b8-bbb7-8d063df92185
2023-06-09 04:58:51.214 INFO 57 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8081 (http)
2023-06-09 04:58:51.221 INFO 57 --- [ main] o.a.coyote.http11.Http11NioProtocol : Initializing ProtocolHandler ["http-nio-8081"]
2023-06-09 04:58:51.221 INFO 57 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2023-06-09 04:58:51.222 INFO 57 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.62]
2023-06-09 04:58:51.274 INFO 57 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2023-06-09 04:58:51.274 INFO 57 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1685 ms
2023-06-09 04:58:51.608 INFO 57 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Starting...
2023-06-09 04:58:51.805 INFO 57 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Start completed.
2023-06-09 04:58:51.934 INFO 57 --- [ main] liquibase.database : Set default schema name to public
2023-06-09 04:58:52.015 INFO 57 --- [ main] liquibase.lockservice : Successfully acquired change log lock
2023-06-09 04:58:52.291 INFO 57 --- [ main] liquibase.changelog : Reading from public.databasechangelog
2023-06-09 04:58:52.395 INFO 57 --- [ main] liquibase.lockservice : Successfully released change log lock
2023-06-09 04:58:52.015 INFO 57 --- [ main] liquibase.lockservice : Successfully acquired change log lock
2023-06-09 04:58:52.291 INFO 57 --- [ main] liquibase.changelog : Reading from public.databasechangelog
2023-06-09 04:58:52.395 INFO 57 --- [ main] liquibase.lockservice : Successfully released change log lock
2023-06-09 11:58:52.740 UTC [105] compreface@frs WARNING: there is no transaction in progress
2023-06-09 04:58:52.820 INFO 57 --- [ main] o.hibernate.jpa.internal.util.LogHelper : HHH000204: Processing PersistenceUnitInfo [name: default]
2023-06-09 04:58:52.858 INFO 57 --- [ main] org.hibernate.Version : HHH000412: Hibernate ORM core version 5.4.33
2023-06-09 04:58:52.964 INFO 57 --- [ main] o.hibernate.annotations.common.Version : HCANN000001: Hibernate Commons Annotations {5.1.2.Final}
2023-06-09 04:58:53.039 INFO 57 --- [ main] org.hibernate.dialect.Dialect : HHH000400: Using dialect: org.hibernate.dialect.PostgreSQL10Dialect
2023-06-09 04:58:53.093 INFO 57 --- [ 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/
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<

2023-06-09 04:58:53.687 INFO 57 --- [ main] o.h.e.t.j.p.i.JtaPlatformInitiator : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2023-06-09 04:58:53.693 INFO 57 --- [ main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
2023-06-09 04:58:55.136 INFO 57 --- [ main] o.s.b.a.e.web.EndpointLinksResolver : Exposing 1 endpoint(s) beneath base path '/actuator'
2023-06-09 04:58:55.609 WARN 57 --- [ 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.
2023-06-09 04:58:55.610 INFO 57 --- [ main] o.s.s.web.DefaultSecurityFilterChain : Will secure Ant [pattern='/v2/api-docs'] with []
2023-06-09 04:58:55.610 WARN 57 --- [ 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.
2023-06-09 04:58:55.610 INFO 57 --- [ main] o.s.s.web.DefaultSecurityFilterChain : Will secure Ant [pattern='/configuration/ui'] with []
2023-06-09 04:58:55.610 WARN 57 --- [ 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.
2023-06-09 04:58:55.610 INFO 57 --- [ main] o.s.s.web.DefaultSecurityFilterChain : Will secure Ant [pattern='/swagger-resources/**'] with []
2023-06-09 04:58:55.610 WARN 57 --- [ 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.
2023-06-09 04:58:55.610 INFO 57 --- [ main] o.s.s.web.DefaultSecurityFilterChain : Will secure Ant [pattern='/configuration/**'] with []

09 04:58:55.610 WARN 57 --- [ 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.
2023-06-09 04:58:55.610 INFO 57 --- [ main] o.s.s.web.DefaultSecurityFilterChain : Will secure Ant [pattern='/swagger-ui**'] with []
2023-06-09 04:58:55.610 WARN 57 --- [ 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.
2023-06-09 04:58:55.610 INFO 57 --- [ main] o.s.s.web.DefaultSecurityFilterChain : Will secure Ant [pattern='/webjars/**'] with []
2023-06-09 04:58:55.610 WARN 57 --- [ 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.
2023-06-09 04:58:55.610 INFO 57 --- [ main] o.s.s.web.DefaultSecurityFilterChain : Will secure Ant [pattern='/lms/**'] with []
2023-06-09 04:58:55.636 INFO 57 --- [ main] o.s.s.web.DefaultSecurityFilterChain : Will not secure Or [Ant [pattern='/oauth/token'], Ant [pattern='/oauth/token_key'], Ant [pattern='/oauth/check_token']]
2023-06-09 04:58:55.645 INFO 57 --- [ main] o.s.s.web.DefaultSecurityFilterChain : Will not secure org.springframework.security.oauth2.config.annotation.web.configuration.ResourceServerConfiguration$NotOAuthRequestMatcher@323b0632
2023-06-09 04:58:55.647 INFO 57 --- [ main] o.s.s.web.DefaultSecurityFilterChain : Will not secure any request
2023-06-09 04:58:55.709 INFO 57 --- [ main] pertySourcedRequestMappingHandlerMapping : Mapped URL path [/v2/api-docs] onto method [springfox.documentation.swagger2.web.Swagger2Controller#getDocumentation(String, HttpServletRequest)]
2023-06-09 04:58:55.768 INFO 57 --- [ main] org.quartz.impl.StdSchedulerFactory : Using default implementation for ThreadExecutor
2023-06-09 04:58:55.776 INFO 57 --- [ main] org.quartz.core.SchedulerSignalerImpl : Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
2023-06-09 04:58:55.776 INFO 57 --- [ main] org.quartz.core.QuartzScheduler : Quartz Scheduler v.2.3.2 created.
2023-06-09 04:58:55.778 INFO 57 --- [ main] o.s.s.quartz.LocalDataSourceJobStore : Using db table-based data access locking (synchronization).
2023-06-09 04:58:55.779 INFO 57 --- [ main] o.s.s.quartz.LocalDataSourceJobStore : JobStoreCMT initialized.
2023-06-09 04:58:55.779 INFO 57 --- [ 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.

2023-06-09 04:58:55.779 INFO 57 --- [ main] org.quartz.impl.StdSchedulerFactory : Quartz scheduler 'statistics scheduler' initialized from an externally provided properties instance.
2023-06-09 04:58:55.779 INFO 57 --- [ main] org.quartz.impl.StdSchedulerFactory : Quartz scheduler version: 2.3.2
2023-06-09 04:58:55.780 INFO 57 --- [ main] org.quartz.core.QuartzScheduler : JobFactory set to: org.springframework.scheduling.quartz.SpringBeanJobFactory@50e6ee24
2023-06-09 04:58:55.821 INFO 57 --- [ main] o.s.s.quartz.LocalDataSourceJobStore : Freed 0 triggers from 'acquired' / 'blocked' state.
2023-06-09 04:58:55.823 INFO 57 --- [ main] o.s.s.quartz.LocalDataSourceJobStore : Recovering 0 jobs that were in-progress at the time of the last shut-down.
2023-06-09 04:58:55.824 INFO 57 --- [ main] o.s.s.quartz.LocalDataSourceJobStore : Recovery complete.
2023-06-09 04:58:55.824 INFO 57 --- [ main] o.s.s.quartz.LocalDataSourceJobStore : Removed 0 'complete' triggers.
2023-06-09 04:58:55.824 INFO 57 --- [ main] o.s.s.quartz.LocalDataSourceJobStore : Removed 0 stale fired job entries.
2023-06-09 04:58:55.827 INFO 57 --- [ main] org.quartz.core.QuartzScheduler : Scheduler statistics scheduler_$_NON_CLUSTERED started.
2023-06-09 04:58:56.367 INFO 57 --- [ main] o.a.coyote.http11.Http11NioProtocol : Starting ProtocolHandler ["http-nio-8081"]
2023-06-09 04:58:56.379 INFO 57 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8081 (http) with context path ''
2023-06-09 04:58:56.380 INFO 57 --- [ main] d.s.w.p.DocumentationPluginsBootstrapper : Context refreshed
2023-06-09 04:58:56.405 INFO 57 --- [ main] d.s.w.p.DocumentationPluginsBootstrapper : Found 1 custom documentation plugin(s)
2023-06-09 04:58:56.450 INFO 57 --- [ main] s.d.s.w.s.ApiListingReferenceScanner : Scanning for api listing references
2023-06-09 04:58:56.593 INFO 57 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: regenerateApiKeyUsingPUT_1
2023-06-09 04:58:56.645 INFO 57 --- [ main] com.exadel.frs.FrsApplication : Started FrsApplication in 7.708 seconds (JVM running for 8.068)
Starting compreface-api
2023-06-09 04:58:58,677 INFO spawned: 'compreface-api' with pid 130
2023-06-09 04:58:58,677 INFO success: compreface-api entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
compreface-api: started

2023-06-09 04:58:59.534 INFO 130 --- [kground-preinit] o.h.validator.internal.util.Version : HV000001: Hibernate Validator 6.2.3.Final
2023-06-09 04:58:59.543 INFO 130 --- [ main] com.exadel.frs.TrainServiceApplication : Starting TrainServiceApplication v0.0.1-SNAPSHOT using Java 11.0.16 on 0ac12110e576 with PID 130 (/app/api/app.jar started by root in /app/api)
2023-06-09 04:58:59.544 INFO 130 --- [ main] com.exadel.frs.TrainServiceApplication : The following 1 profile is active: "dev"
2023-06-09 04:58:59.593 WARN 130 --- [ 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]
2023-06-09 04:59:00.307 INFO 130 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2023-06-09 04:59:00.364 INFO 130 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 51 ms. Found 8 JPA repository interfaces.
2023-06-09 04:59:00.863 INFO 130 --- [ main] o.s.cloud.context.scope.GenericScope : BeanFactory id=9776d44d-52e1-38dc-b671-bd86977f22bf
2023-06-09 04:59:01.195 INFO 130 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'cacheConfig' of type [com.exadel.frs.core.trainservice.config.CacheConfig$$EnhancerBySpringCGLIB$$3613d3b1] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2023-06-09 04:59:01.494 INFO 130 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http)
2023-06-09 04:59:01.502 INFO 130 --- [ main] o.a.coyote.http11.Http11NioProtocol : Initializing ProtocolHandler ["http-nio-8080"]
2023-06-09 04:59:01.502 INFO 130 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2023-06-09 04:59:01.502 INFO 130 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.62]
2023-06-09 04:59:01.565 INFO 130 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2023-06-09 04:59:01.565 INFO 130 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1971 ms
2023-06-09 04:59:01.862 INFO 130 --- [ main] o.hibernate.jpa.internal.util.LogHelper : HHH000204: Processing PersistenceUnitInfo [name: default]
2023-06-09 04:59:01.195 INFO 130 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'cacheConfig' of type [com.exadel.frs.core.trainservice.config.CacheConfig$$EnhancerBySpringCGLIB$$3613d3b1] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2023-06-09 04:59:01.494 INFO 130 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http)
2023-06-09 04:59:01.502 INFO 130 --- [ main] o.a.coyote.http11.Http11NioProtocol : Initializing ProtocolHandler ["http-nio-8080"]
2023-06-09 04:59:01.502 INFO 130 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2023-06-09 04:59:01.502 INFO 130 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.62]
2023-06-09 04:59:01.565 INFO 130 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2023-06-09 04:59:01.565 INFO 130 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1971 ms
2023-06-09 04:59:01.862 INFO 130 --- [ main] o.hibernate.jpa.internal.util.LogHelper : HHH000204: Processing PersistenceUnitInfo [name: default]
2023-06-09 04:59:01.921 INFO 130 --- [ main] org.hibernate.Version : HHH000412: Hibernate ORM core version 5.4.33
2023-06-09 04:59:01.922 INFO 130 --- [ main] org.hibernate.cfg.Environment : HHH000205: Loaded properties from resource hibernate.properties: {hibernate.bytecode.use_reflection_optimizer=false, hibernate.types.print.banner=false}
2023-06-09 04:59:02.019 INFO 130 --- [ main] o.hibernate.annotations.common.Version : HCANN000001: Hibernate Commons Annotations {5.1.2.Final}
2023-06-09 04:59:02.330 INFO 130 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Starting...
2023-06-09 04:59:02.506 INFO 130 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Start completed.
2023-06-09 04:59:02.524 INFO 130 --- [ main] org.hibernate.dialect.Dialect : HHH000400: Using dialect: org.hibernate.dialect.PostgreSQL10Dialect
2023-06-09 04:59:03.259 INFO 130 --- [ main] o.h.e.t.j.p.i.JtaPlatformInitiator : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2023-06-09 04:59:03.267 INFO 130 --- [ main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
2023-06-09 04:59:05.399 INFO 130 --- [ main] o.s.b.a.e.web.EndpointLinksResolver : Exposing 1 endpoint(s) beneath base path '/actuator'
2023-06-09 04:59:05.504 INFO 130 --- [ main] pertySourcedRequestMappingHandlerMapping : Mapped URL path [/v2/api-docs] onto method [springfox.documentation.swagger2.web.Swagger2Controller#getDocumentation(String, HttpServletRequest)]
2023-06-09 04:59:05.561 INFO 130 --- [ main] org.quartz.impl.StdSchedulerFactory : Using default implementation for ThreadExecutor
2023-06-09 04:59:05.572 INFO 130 --- [ main] org.quartz.core.SchedulerSignalerImpl : Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
2023-06-09 04:59:05.572 INFO 130 --- [ main] org.quartz.core.QuartzScheduler : Quartz Scheduler v.2.3.2 created.
2023-06-09 04:59:05.573 INFO 130 --- [ main] org.quartz.simpl.RAMJobStore : RAMJobStore initialized.
2023-06-09 04:59:05.574 INFO 130 --- [ 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.

2023-06-09 04:59:05.574 INFO 130 --- [ main] org.quartz.impl.StdSchedulerFactory : Quartz scheduler 'quartzScheduler' initialized from an externally provided properties instance.
2023-06-09 04:59:05.574 INFO 130 --- [ main] org.quartz.impl.StdSchedulerFactory : Quartz scheduler version: 2.3.2
2023-06-09 04:59:05.575 INFO 130 --- [ main] org.quartz.core.QuartzScheduler : JobFactory set to: org.springframework.scheduling.quartz.SpringBeanJobFactory@7198ab9a
2023-06-09 04:59:05.581 INFO 130 --- [ main] org.quartz.core.QuartzScheduler : Scheduler quartzScheduler_$_NON_CLUSTERED started.
2023-06-09 04:59:06.034 INFO 130 --- [ main] o.a.coyote.http11.Http11NioProtocol : Starting ProtocolHandler ["http-nio-8080"]
2023-06-09 04:59:06.045 INFO 130 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8080 (http) with context path ''
2023-06-09 04:59:06.048 INFO 130 --- [ main] d.s.w.p.DocumentationPluginsBootstrapper : Context refreshed
2023-06-09 04:59:06.072 INFO 130 --- [ main] d.s.w.p.DocumentationPluginsBootstrapper : Found 2 custom documentation plugin(s)
2023-06-09 04:59:06.148 INFO 130 --- [ main] s.d.s.w.s.ApiListingReferenceScanner : Scanning for api listing references
2023-06-09 04:59:06.378 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeBase64UsingPOST_1
2023-06-09 04:59:06.381 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: downloadImgUsingGET_1
2023-06-09 04:59:06.034 INFO 130 --- [ main] o.a.coyote.http11.Http11NioProtocol : Starting ProtocolHandler ["http-nio-8080"]
2023-06-09 04:59:06.045 INFO 130 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8080 (http) with context path ''
2023-06-09 04:59:06.048 INFO 130 --- [ main] d.s.w.p.DocumentationPluginsBootstrapper : Context refreshed
2023-06-09 04:59:06.072 INFO 130 --- [ main] d.s.w.p.DocumentationPluginsBootstrapper : Found 2 custom documentation plugin(s)
2023-06-09 04:59:06.148 INFO 130 --- [ main] s.d.s.w.s.ApiListingReferenceScanner : Scanning for api listing references
2023-06-09 04:59:06.378 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeBase64UsingPOST_1
2023-06-09 04:59:06.381 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: downloadImgUsingGET_1
2023-06-09 04:59:06.430 INFO 130 --- [ main] s.d.s.w.s.ApiListingReferenceScanner : Scanning for api listing references
2023-06-09 04:59:06.446 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: getConfigUsingGET_1
2023-06-09 04:59:06.448 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: getCheckDemoUsingGET_1
2023-06-09 04:59:06.457 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: detectUsingPOST_1
2023-06-09 04:59:06.460 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: detectBase64UsingPOST_1
2023-06-09 04:59:06.463 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: addEmbeddingUsingPOST_1
2023-06-09 04:59:06.465 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: addEmbeddingBase64UsingPOST_1
2023-06-09 04:59:06.466 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: deleteEmbeddingByIdUsingDELETE_1
2023-06-09 04:59:06.467 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: deleteEmbeddingsByIdUsingPOST_1
2023-06-09 04:59:06.468 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: downloadImgUsingGET_2
2023-06-09 04:59:06.471 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: listEmbeddingsUsingGET_1
2023-06-09 04:59:06.478 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeBase64UsingPOST_2
2023-06-09 04:59:06.481 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeFileUsingPOST_1
2023-06-09 04:59:06.482 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: removeAllSubjectEmbeddingsUsingDELETE_1
2023-06-09 04:59:06.484 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: migrateUsingPOST_1
2023-06-09 04:59:06.486 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: handleUsingGET_1
2023-06-09 04:59:06.491 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeUsingPOST_1
2023-06-09 04:59:06.493 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: recognizeBase64UsingPOST_3
2023-06-09 04:59:06.494 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: downloadImgUsingGET_3
2023-06-09 04:59:06.496 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: createSubjectUsingPOST_1
2023-06-09 04:59:06.497 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: deleteSubjectUsingDELETE_1
2023-06-09 04:59:06.498 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: deleteSubjectsUsingDELETE_1
2023-06-09 04:59:06.499 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: listSubjectsUsingGET_1
2023-06-09 04:59:06.500 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: renameSubjectUsingPUT_1
2023-06-09 04:59:06.507 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: verifyUsingPOST_1
2023-06-09 04:59:06.510 INFO 130 --- [ main] .d.s.w.r.o.CachingOperationNameGenerator : Generating unique operation named: verifyBase64UsingPOST_1
2023-06-09 04:59:06.528 INFO 130 --- [ main] com.exadel.frs.TrainServiceApplication : Started TrainServiceApplication in 7.536 seconds (JVM running for 7.846)
Starting compreface-fe
Starting compreface-fe
2023-06-09 04:59:08,781 INFO spawned: 'compreface-fe' with pid 215
2023-06-09 04:59:08,781 INFO success: compreface-fe entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
compreface-fe: started
2023-06-09 04:59:08,792 INFO exited: startup (exit status 0; expected)
2023-06-09 04:59:24.508 INFO 130 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring DispatcherServlet 'dispatcherServlet'
2023-06-09 04:59:24.508 INFO 130 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet'
2023-06-09 04:59:24.509 INFO 130 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Completed initialization in 1 ms
2023-06-09 04:59:24.951271: 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.9265303015708923, _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": "127.0.0.1"}, "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": "127.0.0.1"}, "logger": "src.services.flask_.log_response", "module": "log_response", "traceback": null, "build_version": "dev"}
{"severity": "INFO", "message": "200 OK", "request": {"method": "POST", "path": "/find_faces", "filename": "lenna.jpg", "api_key": "", "remote_addr": "127.0.0.1"}, "logger": "src.services.flask_.log_response", "module": "log_response", "traceback": null, "build_version": "dev"}
2023-06-09 04:59:27.559 INFO 130 --- [nio-8080-exec-1] org.nd4j.linalg.factory.Nd4jBackend : Loaded [CpuBackend] backend
2023-06-09 04:59:27.956 INFO 130 --- [nio-8080-exec-1] org.nd4j.nativeblas.NativeOpsHolder : Number of threads used for linear algebra: 8
2023-06-09 04:59:27.956 WARN 130 --- [nio-8080-exec-1] o.n.l.cpu.nativecpu.CpuNDArrayFactory : *********************************** CPU Feature Check Warning ***********************************
2023-06-09 04:59:27.956 WARN 130 --- [nio-8080-exec-1] o.n.l.cpu.nativecpu.CpuNDArrayFactory : Warning: Initializing ND4J with Generic x86 binary on a CPU with AVX/AVX2 support
2023-06-09 04:59:27.956 WARN 130 --- [nio-8080-exec-1] o.n.l.cpu.nativecpu.CpuNDArrayFactory : Using ND4J with AVX/AVX2 will improve performance. See deeplearning4j.org/cpu for more details
2023-06-09 04:59:27.956 WARN 130 --- [nio-8080-exec-1] o.n.l.cpu.nativecpu.CpuNDArrayFactory : Or set environment variable ND4J_IGNORE_AVX=true to suppress this warning
2023-06-09 04:59:27.956 WARN 130 --- [nio-8080-exec-1] o.n.l.cpu.nativecpu.CpuNDArrayFactory : *************************************************************************************************
2023-06-09 04:59:27.960 INFO 130 --- [nio-8080-exec-1] org.nd4j.nativeblas.Nd4jBlas : Number of threads used for OpenMP BLAS: 8
2023-06-09 04:59:27.963 INFO 130 --- [nio-8080-exec-1] o.n.l.a.o.e.DefaultOpExecutioner : Backend used: [CPU]; OS: [Linux]
2023-06-09 04:59:27.963 INFO 130 --- [nio-8080-exec-1] o.n.l.a.o.e.DefaultOpExecutioner : Cores: [16]; Memory: [4.0GB];
2023-06-09 04:59:27.963 INFO 130 --- [nio-8080-exec-1] o.n.l.a.o.e.DefaultOpExecutioner : Blas vendor: [OPENBLAS]
2023-06-09 04:59:28.063 INFO 130 --- [PG-JDBC I/O (2)] c.e.f.c.t.s.NotificationReceiverService : /channels3/ channel name: face_collection_update_msg payload {
"cacheAction" : "UPDATE",
"apiKey" : "9d2a8fc4-12d1-4ee7-8473-13e3d1195499",
"uuid" : "17bf55e7-bd93-43f1-aa51-62f6b2b0824c"
}
{"severity": "INFO", "message": "200 OK", "request": {"method": "GET", "path": "/status", "filename": "", "api_key": "", "remote_addr": "127.0.0.1"}, "logger": "src.services.flask_.log_response", "module": "log_response", "traceback": null, "build_version": "dev"}
xxx.xxx.x.xx - - [09/Jun/2023:04:59:28 -0700] "POST /api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8 HTTP/1.1" 200 257 "-" "axios/0.27.2"
{"severity": "DEBUG", "message": "Found: BoundingBoxDTO(x_min=173, y_min=158, x_max=386, y_max=417, probability=0.9265303015708923, _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": "127.0.0.1"}, "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": "127.0.0.1"}, "logger": "src.services.flask_.log_response", "module": "log_response", "traceback": null, "build_version": "dev"}
xxx.xxx.x.xx - - [09/Jun/2023:04:59:55 -0700] "POST /api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8 HTTP/1.1" 200 257 "-" "axios/0.27.2"
2023-06-09 05:00:00.047 INFO 130 --- [ scheduling-1] c.e.f.c.t.service.ModelStatisticService : The statistics have been updated(0) and recorded(1)
2023-06-09 05:00:00.047 INFO 130 --- [ scheduling-1] c.e.f.c.t.service.ModelStatisticService : The statistics have been updated(0) and recorded(1)
2023-06-09 05:00:25.534157: 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.9265303015708923, _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": "127.0.0.1"}, "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": "127.0.0.1"}, "logger": "src.services.flask_.log_response", "module": "log_response", "traceback": null, "build_version": "dev"}
xxx.xxx.x.xx - - [09/Jun/2023:05:00:28 -0700] "POST /api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8 HTTP/1.1" 200 257 "-" "axios/0.27.2"
{"severity": "DEBUG", "message": "Found: BoundingBoxDTO(x_min=173, y_min=158, x_max=386, y_max=417, probability=0.9265303015708923, _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": "127.0.0.1"}, "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": "127.0.0.1"}, "logger": "src.services.flask_.log_response", "module": "log_response", "traceback": null, "build_version": "dev"}
xxx.xxx.x.xx - - [09/Jun/2023:05:00:56 -0700] "POST /api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8 HTTP/1.1" 200 257 "-" "axios/0.27.2"
{"severity": "DEBUG", "message": "Found: BoundingBoxDTO(x_min=173, y_min=158, x_max=386, y_max=417, probability=0.9265303015708923, _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": "127.0.0.1"}, "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": "127.0.0.1"}, "logger": "src.services.flask_.log_response", "module": "log_response", "traceback": null, "build_version": "dev"}
xxx.xxx.x.xx - - [09/Jun/2023:05:01:27 -0700] "POST /api/v1/recognition/recognize?face_plugins=undefined&det_prob_threshold=0.8 HTTP/1.1" 200 257 "-" "axios/0.27.2"
'

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

lenna.jpg on repeat

Description

Contributor guide

Assessment

Get new issues in your inbox