search

exadel-inc / CompreFace

Leading free and open-source face recognition system
https://exadel.com/accelerator-showcase/compreface/
Apache License 2.0
5.67k stars 773 forks source link

lenna.jpg on repeat #1085

Open clowncracker opened 1 year ago

clowncracker commented 1 year ago

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):

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

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

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": "", "remoteaddr": "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": "", "remoteaddr": "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_probthreshold=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$_NONCLUSTERED paused. 2023-06-09 04:58:35.000 INFO 134 --- [ionShutdownHook] org.quartz.core.QuartzScheduler : Scheduler quartzScheduler$_NONCLUSTERED shutting down. 2023-06-09 04:58:35.000 INFO 134 --- [ionShutdownHook] org.quartz.core.QuartzScheduler : Scheduler quartzScheduler$_NONCLUSTERED paused. 2023-06-09 04:58:35.000 INFO 134 --- [ionShutdownHook] org.quartz.core.QuartzScheduler : Scheduler quartzScheduler$_NONCLUSTERED 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$_NONCLUSTERED paused. 2023-06-09 04:58:35.394 INFO 57 --- [ionShutdownHook] org.quartz.core.QuartzScheduler : Scheduler statistics scheduler$_NONCLUSTERED shutting down. 2023-06-09 04:58:35.395 INFO 57 --- [ionShutdownHook] org.quartz.core.QuartzScheduler : Scheduler statistics scheduler$_NONCLUSTERED 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

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

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

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

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]

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

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": "", "remoteaddr": "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": "", "remoteaddr": "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": "", "remoteaddr": "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": "", "remoteaddr": "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": "", "remoteaddr": "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": "", "remoteaddr": "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": "", "remoteaddr": "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" '

pospielov commented 1 year ago

lenna.jpg is an image that sends https://github.com/jakowenko/double-take solution to CompreFace. Not sure for what purposes, as it's not our solution. As for memory consumption - it shouldn't increase all the time. It should stop at some point. Could you confirm it?