Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Can not start up Openboxes #2334

Closed
ghost opened this issue Apr 14, 2021 · 9 comments
Closed

Can not start up Openboxes #2334

ghost opened this issue Apr 14, 2021 · 9 comments

Comments

@ghost
Copy link

ghost commented Apr 14, 2021

I need your help to share some ideas.

git clone https://github.com/openboxes/openboxes.git

cd .\openboxes\docker\

docker-compose up

HTTP Status 404 - Not Found

Thanks and looking forward to your reply.

FILE:docker-compose.yml
version: "2"
services:
db:
image: mysql:5.7
environment:
MYSQL_ROOT_PASSWORD: root
MYSQL_DATABASE: openboxes
MYSQL_USER: openboxes
MYSQL_PASSWORD: openboxes
volumes:
- ./openboxes-mysql.cnf:/etc/mysql/conf.d/openboxes-mysql.cnf
- ./mysql/:/var/lib/mysql/

tomcat:
image: tomcat:7.0.94
ports:
- "8072:8080"
volumes:
- ./openboxes.war:/usr/local/tomcat/webapps/openboxes.war
- ./openboxes-config.properties:/root/.grails/openboxes-config.properties
environment:
CATALINA_OPTS: "$CATALINA_OPTS -server -Xms1024m -Xmx2024m -XX:MaxPermSize=256m -Djava.security.egd=file:/dev/./urandom"

LOG:
OpenJDK 64-Bit Server VM warning: ignoring option MaxPermSize=256m; support was removed in 8.0
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server version: Apache Tomcat/7.0.94
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server built: Apr 10 2019 16:56:40 UTC
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server number: 7.0.94.0
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: OS Name: Linux
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: OS Version: 5.4.72-microsoft-standard-WSL2
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Architecture: amd64
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Java Home: /usr/local/openjdk-8/jre
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: JVM Version: 1.8.0_222-b10
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: JVM Vendor: Oracle Corporation
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: CATALINA_BASE: /usr/local/tomcat
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: CATALINA_HOME: /usr/local/tomcat
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.util.logging.config.file=/usr/local/tomcat/conf/logging.properties
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Xms1024m
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Xmx2024m
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:MaxPermSize=256m
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.security.egd=file:/dev/./urandom
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dignore.endorsed.dirs=
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcatalina.base=/usr/local/tomcat
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcatalina.home=/usr/local/tomcat
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.io.tmpdir=/usr/local/tomcat/temp
Apr 14, 2021 11:03:37 AM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFO: Loaded APR based Apache Tomcat Native library 1.2.21 using APR version 1.5.2.
Apr 14, 2021 11:03:37 AM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFO: APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
Apr 14, 2021 11:03:37 AM org.apache.catalina.core.AprLifecycleListener initializeSSL
INFO: OpenSSL successfully initialized (OpenSSL 1.1.0k 28 May 2019)
Apr 14, 2021 11:03:37 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-apr-8080"]
Apr 14, 2021 11:03:37 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["ajp-apr-8009"]
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 1884 ms
Apr 14, 2021 11:03:37 AM org.apache.catalina.core.StandardService startInternal
INFO: Starting service Catalina
Apr 14, 2021 11:03:37 AM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.94
Apr 14, 2021 11:03:37 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /usr/local/tomcat/webapps/manager
Apr 14, 2021 11:03:38 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deployment of web application directory /usr/local/tomcat/webapps/manager has finished in 866 ms
Apr 14, 2021 11:03:38 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /usr/local/tomcat/webapps/examples
Apr 14, 2021 11:03:39 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deployment of web application directory /usr/local/tomcat/webapps/examples has finished in 777 ms
Apr 14, 2021 11:03:39 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /usr/local/tomcat/webapps/docs
Apr 14, 2021 11:03:39 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deployment of web application directory /usr/local/tomcat/webapps/docs has finished in 128 ms
Apr 14, 2021 11:03:39 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /usr/local/tomcat/webapps/ROOT
Apr 14, 2021 11:03:39 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deployment of web application directory /usr/local/tomcat/webapps/ROOT has finished in 99 ms
Apr 14, 2021 11:03:39 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /usr/local/tomcat/webapps/host-manager
Apr 14, 2021 11:03:39 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deployment of web application directory /usr/local/tomcat/webapps/host-manager has finished in 109 ms
Apr 14, 2021 11:03:39 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /usr/local/tomcat/webapps/openboxes.war
Apr 14, 2021 11:03:39 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deployment of web application directory /usr/local/tomcat/webapps/openboxes.war has finished in 101 ms
Apr 14, 2021 11:03:40 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-apr-8080"]
Apr 14, 2021 11:03:40 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["ajp-apr-8009"]
Apr 14, 2021 11:03:40 AM org.apache.catalina.startup.Catalina start
INFO: Server startup in 2273 ms

@jmiranda
Copy link
Member

INFO: JVM Version: 1.8.0_222-b10

Thanks for the ticket. You need to switch to Java 7.

@ghost
Copy link
Author

ghost commented Apr 14, 2021

Thank you for the advice.
I have tried the following. But I couldn't make it work.

Thanks and looking forward to your reply.

HTTP Status 404 - Not Found

FILE:docker-compose.yml
version: "2"
services:
db:
image: mysql:5.7
environment:
MYSQL_ROOT_PASSWORD: root
MYSQL_DATABASE: openboxes
MYSQL_USER: openboxes
MYSQL_PASSWORD: openboxes
volumes:
- ./openboxes-mysql.cnf:/etc/mysql/conf.d/openboxes-mysql.cnf
- ./mysql/:/var/lib/mysql/

tomcat:
image: tomcat:7.0.94-jre7-alpine
ports:
- "8072:8080"
volumes:
- ./openboxes.war:/usr/local/tomcat/webapps/openboxes.war
- ./openboxes-config.properties:/root/.grails/openboxes-config.properties
environment:
CATALINA_OPTS: "$CATALINA_OPTS -server -Xms1024m -Xmx2024m -XX:MaxPermSize=256m -Djava.security.egd=file:/dev/./urandom"

LOG:
Apr 14, 2021 5:30:34 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server version: Apache Tomcat/7.0.94
Apr 14, 2021 5:30:34 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server built: Apr 10 2019 16:56:40 UTC
Apr 14, 2021 5:30:34 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server number: 7.0.94.0
Apr 14, 2021 5:30:34 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: OS Name: Linux
Apr 14, 2021 5:30:34 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: OS Version: 5.4.72-microsoft-standard-WSL2
Apr 14, 2021 5:30:34 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Architecture: amd64
Apr 14, 2021 5:30:34 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Java Home: /usr/lib/jvm/java-1.7-openjdk/jre
Apr 14, 2021 5:30:34 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: JVM Version: 1.7.0_211-b02
Apr 14, 2021 5:30:34 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: JVM Vendor: Oracle Corporation
Apr 14, 2021 5:30:34 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: CATALINA_BASE: /usr/local/tomcat
Apr 14, 2021 5:30:35 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: CATALINA_HOME: /usr/local/tomcat
Apr 14, 2021 5:30:35 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.util.logging.config.file=/usr/local/tomcat/conf/logging.properties
Apr 14, 2021 5:30:35 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
Apr 14, 2021 5:30:35 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
Apr 14, 2021 5:30:35 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Xms1024m
Apr 14, 2021 5:30:35 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Xmx2024m
Apr 14, 2021 5:30:35 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:MaxPermSize=256m
Apr 14, 2021 5:30:35 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.security.egd=file:/dev/./urandom
Apr 14, 2021 5:30:35 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dignore.endorsed.dirs=
Apr 14, 2021 5:30:35 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcatalina.base=/usr/local/tomcat
Apr 14, 2021 5:30:35 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcatalina.home=/usr/local/tomcat
Apr 14, 2021 5:30:35 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.io.tmpdir=/usr/local/tomcat/temp
Apr 14, 2021 5:30:35 PM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFO: Loaded APR based Apache Tomcat Native library 1.2.21 using APR version 1.6.5.
Apr 14, 2021 5:30:35 PM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFO: APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
Apr 14, 2021 5:30:35 PM org.apache.catalina.core.AprLifecycleListener initializeSSL
INFO: OpenSSL successfully initialized (OpenSSL 1.1.1b 26 Feb 2019)
Apr 14, 2021 5:30:35 PM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-apr-8080"]
Apr 14, 2021 5:30:35 PM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["ajp-apr-8009"]
Apr 14, 2021 5:30:35 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 2039 ms
Apr 14, 2021 5:30:35 PM org.apache.catalina.core.StandardService startInternal
INFO: Starting service Catalina
Apr 14, 2021 5:30:35 PM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.94
Apr 14, 2021 5:30:35 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /usr/local/tomcat/webapps/manager
Apr 14, 2021 5:30:37 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deployment of web application directory /usr/local/tomcat/webapps/manager has finished in 1,545 ms
Apr 14, 2021 5:30:37 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /usr/local/tomcat/webapps/examples
Apr 14, 2021 5:30:37 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deployment of web application directory /usr/local/tomcat/webapps/examples has finished in 626 ms
Apr 14, 2021 5:30:37 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /usr/local/tomcat/webapps/docs
Apr 14, 2021 5:30:37 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deployment of web application directory /usr/local/tomcat/webapps/docs has finished in 106 ms
Apr 14, 2021 5:30:37 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /usr/local/tomcat/webapps/ROOT
Apr 14, 2021 5:30:37 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deployment of web application directory /usr/local/tomcat/webapps/ROOT has finished in 75 ms
Apr 14, 2021 5:30:37 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /usr/local/tomcat/webapps/host-manager
Apr 14, 2021 5:30:37 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deployment of web application directory /usr/local/tomcat/webapps/host-manager has finished in 87 ms
Apr 14, 2021 5:30:37 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /usr/local/tomcat/webapps/openboxes.war
Apr 14, 2021 5:30:38 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deployment of web application directory /usr/local/tomcat/webapps/openboxes.war has finished in 147 ms
Apr 14, 2021 5:30:38 PM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-apr-8080"]
Apr 14, 2021 5:30:38 PM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["ajp-apr-8009"]
Apr 14, 2021 5:30:38 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 2799 ms

@jmiranda
Copy link
Member

Sorry it's been awhile since I've run the application using Docker, but I think it requires you to have a deployable WAR file generated before running docker.

So here are the instructions I would recommend

To use a stable release WAR file

git clone https://github.com/openboxes/openboxes.git
cd openboxes/docker
wget https://github.com/openboxes/openboxes/releases/download/v0.8.15-hotfix1/openboxes.war openboxes.war
docker-compose up

To use an unstable snapshot WAR file generated from source code

git clone https://github.com/openboxes/openboxes.git
cd openboxes
grails war docker/openboxes.war
cd docker
docker-compose up

@ghost
Copy link
Author

ghost commented Apr 15, 2021

Thank you for the advice.
I have tried the following. But I couldn't make it work.

git clone https://github.com/openboxes/openboxes.git
cd openboxes/docker
wget https://github.com/openboxes/openboxes/releases/download/v0.8.15-hotfix1/openboxes.war openboxes.war
docker-compose up

Thanks and looking forward to your reply.

HTTP Status 404 - Not Found

LOG:

INFO: Server startup in 441257 ms
Apr 15, 2021 1:16:52 AM org.apache.catalina.loader.WebappClassLoaderBase findResourceInternal
INFO: Illegal access: this web application instance has been stopped already. Could not load . The eventual following stack trace is caused by an error thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access, and has no functional impact.
log4j:WARN No appenders could be found for logger (grails.app.job.org.pih.warehouse.jobs.AssignIdentifierJob).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http:https://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.

@jmiranda
Copy link
Member

Hmm. There's nothing in the snippet above that helps narrow down the issue. Is there more to the log? Any other errors above?

The initial startup usually takes about 20-30 minutes, if not longer because there are hundreds of database migrations that need to be executed. So the fact that your instance started up in less than 8 minutes probably suggests it failed while running database migrations.

INFO: Server startup in 441257 ms

@jmiranda
Copy link
Member

For reference, here's what it looks like when it starts up successfully.
log.txt

Note: In case you noticed the 30 second startup time, all database migrations for this instance were executed during a previous docker-compose up.

tomcat_1  | INFO: Server startup in 35583 ms

@ghost
Copy link
Author

ghost commented Apr 15, 2021

Thanks for the advice.
All logs retrieved.

LOG:

PS C:\Users\KITM7332\openboxes\docker> docker-compose up
WARNING: The CATALINA_OPTS variable is not set. Defaulting to a blank string.
Starting docker_db_1     ... done
Starting docker_tomcat_1 ... done
Attaching to docker_tomcat_1, docker_db_1
db_1      | 2021-04-15 02:45:12+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 5.7.33-1debian10 started.
db_1      | 2021-04-15 02:45:13+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
db_1      | 2021-04-15 02:45:13+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 5.7.33-1debian10 started.
db_1      | mysqld: [Warning] World-writable config file '/etc/mysql/conf.d/openboxes-mysql.cnf' is ignored.
db_1      | 2021-04-15T02:45:14.314193Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
db_1      | 2021-04-15T02:45:14.325120Z 0 [Note] mysqld (mysqld 5.7.33) starting as process 1 ...
db_1      | 2021-04-15T02:45:14.338016Z 0 [Warning] Setting lower_case_table_names=2 because file system for /var/lib/mysql/ is case insensitive
db_1      | 2021-04-15T02:45:14.345175Z 0 [Note] InnoDB: PUNCH HOLE support available
db_1      | 2021-04-15T02:45:14.345266Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
db_1      | 2021-04-15T02:45:14.345276Z 0 [Note] InnoDB: Uses event mutexes
db_1      | 2021-04-15T02:45:14.345283Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
db_1      | 2021-04-15T02:45:14.345289Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
db_1      | 2021-04-15T02:45:14.345397Z 0 [Note] InnoDB: Using Linux native AIO
db_1      | 2021-04-15T02:45:14.349526Z 0 [Note] InnoDB: Number of pools: 1
db_1      | 2021-04-15T02:45:14.351689Z 0 [Note] InnoDB: Using CPU crc32 instructions
db_1      | 2021-04-15T02:45:14.363852Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
db_1      | 2021-04-15T02:45:14.393088Z 0 [Note] InnoDB: Completed initialization of buffer pool
db_1      | 2021-04-15T02:45:14.397471Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
db_1      | 2021-04-15T02:45:14.501277Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.startup.VersionLoggerListener log
tomcat_1  | INFO: Server version:        Apache Tomcat/7.0.94
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.startup.VersionLoggerListener log
tomcat_1  | INFO: Server built:          Apr 10 2019 16:56:40 UTC
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.startup.VersionLoggerListener log
tomcat_1  | INFO: Server number:         7.0.94.0
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.startup.VersionLoggerListener log
tomcat_1  | INFO: OS Name:               Linux
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.startup.VersionLoggerListener log
tomcat_1  | INFO: OS Version:            5.4.72-microsoft-standard-WSL2
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.startup.VersionLoggerListener log
tomcat_1  | INFO: Architecture:          amd64
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.startup.VersionLoggerListener log
tomcat_1  | INFO: Java Home:             /usr/lib/jvm/java-1.7-openjdk/jre
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.startup.VersionLoggerListener log
tomcat_1  | INFO: JVM Version:           1.7.0_211-b02
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.startup.VersionLoggerListener log
tomcat_1  | INFO: JVM Vendor:            Oracle Corporation
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.startup.VersionLoggerListener log
tomcat_1  | INFO: CATALINA_BASE:         /usr/local/tomcat
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.startup.VersionLoggerListener log
tomcat_1  | INFO: CATALINA_HOME:         /usr/local/tomcat
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.startup.VersionLoggerListener log
tomcat_1  | INFO: Command line argument: -Djava.util.logging.config.file=/usr/local/tomcat/conf/logging.properties
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.startup.VersionLoggerListener log
tomcat_1  | INFO: Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.startup.VersionLoggerListener log
tomcat_1  | INFO: Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.startup.VersionLoggerListener log
tomcat_1  | INFO: Command line argument: -Xms1024m
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.startup.VersionLoggerListener log
tomcat_1  | INFO: Command line argument: -Xmx2024m
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.startup.VersionLoggerListener log
tomcat_1  | INFO: Command line argument: -XX:MaxPermSize=256m
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.startup.VersionLoggerListener log
tomcat_1  | INFO: Command line argument: -Djava.security.egd=file:/dev/./urandom
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.startup.VersionLoggerListener log
tomcat_1  | INFO: Command line argument: -Dignore.endorsed.dirs=
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.startup.VersionLoggerListener log
tomcat_1  | INFO: Command line argument: -Dcatalina.base=/usr/local/tomcat
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.startup.VersionLoggerListener log
tomcat_1  | INFO: Command line argument: -Dcatalina.home=/usr/local/tomcat
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.startup.VersionLoggerListener log
tomcat_1  | INFO: Command line argument: -Djava.io.tmpdir=/usr/local/tomcat/temp
db_1      | 2021-04-15T02:45:15.642552Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
db_1      | 2021-04-15T02:45:15.647476Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
tomcat_1  | INFO: Loaded APR based Apache Tomcat Native library 1.2.21 using APR version 1.6.5.
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
tomcat_1  | INFO: APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
tomcat_1  | Apr 15, 2021 2:45:15 AM org.apache.catalina.core.AprLifecycleListener initializeSSL
tomcat_1  | INFO: OpenSSL successfully initialized (OpenSSL 1.1.1b  26 Feb 2019)
db_1      | 2021-04-15T02:45:15.842570Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
db_1      | 2021-04-15T02:45:15.851117Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
db_1      | 2021-04-15T02:45:15.851190Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
db_1      | 2021-04-15T02:45:15.873096Z 0 [Note] InnoDB: 5.7.33 started; log sequence number 21337374
db_1      | 2021-04-15T02:45:15.898046Z 0 [Note] Plugin 'FEDERATED' is disabled.
db_1      | 2021-04-15T02:45:15.907146Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
db_1      | 2021-04-15T02:45:16.034968Z 0 [Note] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.
db_1      | 2021-04-15T02:45:16.037317Z 0 [Note] Skipping generation of SSL certificates as certificate files are present in data directory.
db_1      | 2021-04-15T02:45:16.097797Z 0 [Warning] CA certificate ca.pem is self signed.
db_1      | 2021-04-15T02:45:16.101312Z 0 [Note] Skipping generation of RSA key pair as key files are present in data directory.
db_1      | 2021-04-15T02:45:16.116254Z 0 [Note] Server hostname (bind-address): '*'; port: 3306
tomcat_1  | Apr 15, 2021 2:45:16 AM org.apache.coyote.AbstractProtocol init
tomcat_1  | INFO: Initializing ProtocolHandler ["http-apr-8080"]
db_1      | 2021-04-15T02:45:16.123261Z 0 [Note] IPv6 is available.
db_1      | 2021-04-15T02:45:16.125227Z 0 [Note]   - '::' resolves to '::';
db_1      | 2021-04-15T02:45:16.125601Z 0 [Note] Server socket created on IP: '::'.
db_1      | 2021-04-15T02:45:16.160625Z 0 [Warning] Insecure configuration for --pid-file: Location '/var/run/mysqld' in the path is accessible to all OS users. Consider choosing a different directory.
tomcat_1  | Apr 15, 2021 2:45:16 AM org.apache.coyote.AbstractProtocol init
tomcat_1  | INFO: Initializing ProtocolHandler ["ajp-apr-8009"]
tomcat_1  | Apr 15, 2021 2:45:16 AM org.apache.catalina.startup.Catalina load
tomcat_1  | INFO: Initialization processed in 2719 ms
tomcat_1  | Apr 15, 2021 2:45:16 AM org.apache.catalina.core.StandardService startInternal
tomcat_1  | INFO: Starting service Catalina
db_1      | 2021-04-15T02:45:16.326387Z 0 [Note] InnoDB: Buffer pool(s) load completed at 210415  2:45:16
tomcat_1  | Apr 15, 2021 2:45:16 AM org.apache.catalina.core.StandardEngine startInternal
tomcat_1  | INFO: Starting Servlet Engine: Apache Tomcat/7.0.94
tomcat_1  | Apr 15, 2021 2:45:16 AM org.apache.catalina.startup.HostConfig deployWAR
tomcat_1  | INFO: Deploying web application archive /usr/local/tomcat/webapps/openboxes.war
db_1      | 2021-04-15T02:45:17.542534Z 0 [Note] Event Scheduler: Loaded 0 events
db_1      | 2021-04-15T02:45:17.543594Z 0 [Note] mysqld: ready for connections.
db_1      | Version: '5.7.33'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  MySQL Community Server (GPL)
tomcat_1  | Apr 15, 2021 2:45:31 AM org.apache.catalina.startup.TldConfig execute
tomcat_1  | INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
tomcat_1  | Using configuration locations [classpath:openboxes-config.properties, classpath:openboxes-config.groovy, file:/root/.grails/openboxes-config.properties, file:/root/.grails/openboxes-config.groovy] [production]
tomcat_1  | Unable to load specified config location classpath:openboxes-config.properties : class path resource [openboxes-config.properties] cannot be opened because it does not exist
tomcat_1  | Unable to load specified config location classpath:openboxes-config.groovy : class path resource [openboxes-config.groovy] cannot be opened because it does not exist
tomcat_1  | Unable to load specified config location file:/root/.grails/openboxes-config.groovy : /root/.grails/openboxes-config.groovy (No such file or directory)
tomcat_1  | 2021-04-15 02:45:33,733 [localhost-startStop-1] INFO  context.ContextLoader  - Root WebApplicationContext: initialization started
tomcat_1  | 2021-04-15 02:45:33,767 [localhost-startStop-1] INFO  support.XmlWebApplicationContext  - Refreshing Root WebApplicationContext: startup date [Thu Apr 15 02:45:33 GMT 2021]; root of context hierarchy
tomcat_1  | 2021-04-15 02:45:33,820 [localhost-startStop-1] INFO  xml.XmlBeanDefinitionReader  - Loading XML bean definitions from ServletContext resource [/WEB-INF/applicationContext.xml]
tomcat_1  | 2021-04-15 02:45:34,052 [localhost-startStop-1] INFO  support.DefaultListableBeanFactory  - Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@548aeebf: defining beans [grailsApplication,pluginManager,grailsConfigurator,grailsResourceLoader,grailsResourceHolder,characterEncodingFilter]; root of factory hierarchy
tomcat_1  | 2021-04-15 02:45:44,738 [localhost-startStop-1] INFO  cfg.Environment  - Hibernate 3.3.1.GA
tomcat_1  | 2021-04-15 02:45:44,746 [localhost-startStop-1] INFO  cfg.Environment  - hibernate.properties not found
tomcat_1  | 2021-04-15 02:45:44,753 [localhost-startStop-1] INFO  cfg.Environment  - Bytecode provider name : javassist
tomcat_1  | 2021-04-15 02:45:44,763 [localhost-startStop-1] INFO  cfg.Environment  - using JDK 1.4 java.sql.Timestamp handling
tomcat_1  | 2021-04-15 02:45:50,863 [localhost-startStop-1] INFO  annotation.ClassPathBeanDefinitionScanner  - JSR-250 'javax.annotation.ManagedBean' found and supported for component scanning
tomcat_1  | 2021-04-15 02:45:52,737 [MLog-Init-Reporter] INFO  log.MLog  - MLog clients using slf4j logging.
tomcat_1  | 2021-04-15 02:45:55,763 [localhost-startStop-1] INFO  c3p0.C3P0Registry  - Initializing c3p0-0.9.5.3 [built 27-January-2019 00:11:37 -0800; debug? true; trace: 10]
tomcat_1  | 2021-04-15 02:45:56,899 [localhost-startStop-1] INFO  impl.AbstractPoolBackedDataSource  - Initializing c3p0 pool... com.mchange.v2.c3p0.ComboPooledDataSource [ acquireIncrement -> 5, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, contextClassLoaderSource -> caller, dataSourceName -> 1br5hqbag1mntn62fe84fb|2abaa1d8, debugUnreturnedConnectionStackTraces -> false, description -> null, driverClass -> com.mysql.jdbc.Driver, extensions -> {}, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, forceSynchronousCheckins -> false, forceUseNamedDriverClass -> false, identityToken -> 1br5hqbag1mntn62fe84fb|2abaa1d8, idleConnectionTestPeriod -> 7200, initialPoolSize -> 10, jdbcUrl -> jdbc:mysql:https://db:3306/openboxes?autoReconnect=true&zeroDateTimeBehavior=convertToNull&verifyServerCertificate=false, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 14400, maxIdleTime -> 0, maxIdleTimeExcessConnections -> 1800, maxPoolSize -> 100, maxStatements -> 180, maxStatementsPerConnection -> 0, minPoolSize -> 5, numHelperThreads -> 3, preferredTestQuery -> SELECT 1, privilegeSpawnedThreads -> false, properties -> {user=******, password=******}, propertyCycle -> 0, statementCacheNumDeferredCloseThreads -> 1, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 0, userOverrides -> {}, usesTraditionalReflectiveProxies -> false ]
tomcat_1  | Thu Apr 15 02:45:57 GMT 2021 WARN: Establishing SSL connection without server's identity verification is not recommended. According to MySQL 5.5.45+, 5.6.26+ and 5.7.6+ requirements SSL connection must be established by default if explicit option isn't set. For compliance with existing applications not using SSL the verifyServerCertificate property is set to 'false'. You need either to explicitly disable SSL by setting useSSL=false, or set useSSL=true and provide truststore for server certificate verification.
tomcat_1  | Thu Apr 15 02:45:57 GMT 2021 WARN: Establishing SSL connection without server's identity verification is not recommended. According to MySQL 5.5.45+, 5.6.26+ and 5.7.6+ requirements SSL connection must be established by default if explicit option isn't set. For compliance with existing applications not using SSL the verifyServerCertificate property is set to 'false'. You need either to explicitly disable SSL by setting useSSL=false, or set useSSL=true and provide truststore for server certificate verification.
tomcat_1  | Thu Apr 15 02:45:57 GMT 2021 WARN: Establishing SSL connection without server's identity verification is not recommended. According to MySQL 5.5.45+, 5.6.26+ and 5.7.6+ requirements SSL connection must be established by default if explicit option isn't set. For compliance with existing applications not using SSL the verifyServerCertificate property is set to 'false'. You need either to explicitly disable SSL by setting useSSL=false, or set useSSL=true and provide truststore for server certificate verification.
tomcat_1  | Thu Apr 15 02:45:58 GMT 2021 WARN: Establishing SSL connection without server's identity verification is not recommended. According to MySQL 5.5.45+, 5.6.26+ and 5.7.6+ requirements SSL connection must be established by default if explicit option isn't set. For compliance with existing applications not using SSL the verifyServerCertificate property is set to 'false'. You need either to explicitly disable SSL by setting useSSL=false, or set useSSL=true and provide truststore for server certificate verification.
tomcat_1  | Thu Apr 15 02:45:58 GMT 2021 WARN: Establishing SSL connection without server's identity verification is not recommended. According to MySQL 5.5.45+, 5.6.26+ and 5.7.6+ requirements SSL connection must be established by default if explicit option isn't set. For compliance with existing applications not using SSL the verifyServerCertificate property is set to 'false'. You need either to explicitly disable SSL by setting useSSL=false, or set useSSL=true and provide truststore for server certificate verification.
tomcat_1  | Thu Apr 15 02:45:58 GMT 2021 WARN: Establishing SSL connection without server's identity verification is not recommended. According to MySQL 5.5.45+, 5.6.26+ and 5.7.6+ requirements SSL connection must be established by default if explicit option isn't set. For compliance with existing applications not using SSL the verifyServerCertificate property is set to 'false'. You need either to explicitly disable SSL by setting useSSL=false, or set useSSL=true and provide truststore for server certificate verification.
tomcat_1  | Thu Apr 15 02:45:58 GMT 2021 WARN: Establishing SSL connection without server's identity verification is not recommended. According to MySQL 5.5.45+, 5.6.26+ and 5.7.6+ requirements SSL connection must be established by default if explicit option isn't set. For compliance with existing applications not using SSL the verifyServerCertificate property is set to 'false'. You need either to explicitly disable SSL by setting useSSL=false, or set useSSL=true and provide truststore for server certificate verification.
tomcat_1  | Thu Apr 15 02:45:58 GMT 2021 WARN: Establishing SSL connection without server's identity verification is not recommended. According to MySQL 5.5.45+, 5.6.26+ and 5.7.6+ requirements SSL connection must be established by default if explicit option isn't set. For compliance with existing applications not using SSL the verifyServerCertificate property is set to 'false'. You need either to explicitly disable SSL by setting useSSL=false, or set useSSL=true and provide truststore for server certificate verification.
tomcat_1  | Thu Apr 15 02:45:58 GMT 2021 WARN: Establishing SSL connection without server's identity verification is not recommended. According to MySQL 5.5.45+, 5.6.26+ and 5.7.6+ requirements SSL connection must be established by default if explicit option isn't set. For compliance with existing applications not using SSL the verifyServerCertificate property is set to 'false'. You need either to explicitly disable SSL by setting useSSL=false, or set useSSL=true and provide truststore for server certificate verification.
tomcat_1  | Thu Apr 15 02:45:58 GMT 2021 WARN: Establishing SSL connection without server's identity verification is not recommended. According to MySQL 5.5.45+, 5.6.26+ and 5.7.6+ requirements SSL connection must be established by default if explicit option isn't set. For compliance with existing applications not using SSL the verifyServerCertificate property is set to 'false'. You need either to explicitly disable SSL by setting useSSL=false, or set useSSL=true and provide truststore for server certificate verification.
tomcat_1  | 2021-04-15 02:45:58,686 [localhost-startStop-1] INFO  annotations.Version  - Hibernate Annotations 3.4.0.GA
tomcat_1  | 2021-04-15 02:45:58,896 [localhost-startStop-1] INFO  common.Version  - Hibernate Commons Annotations 3.1.0.GA
tomcat_1  | 2021-04-15 02:46:00,047 [localhost-startStop-1] WARN  commons.GrailsDomainConfigurationUtil  - Derived properties may not be constrained. Property [monthRequested] of domain class org.pih.warehouse.requisition.Requisition will not be checked during validation.
tomcat_1  | 2021-04-15 02:46:00,048 [localhost-startStop-1] WARN  commons.GrailsDomainConfigurationUtil  - Derived properties may not be constrained. Property [statusSortOrder] of domain class org.pih.warehouse.requisition.Requisition will not be checked during validation.
tomcat_1  | 2021-04-15 02:46:00,273 [localhost-startStop-1] WARN  commons.GrailsDomainConfigurationUtil  - Derived properties may not be constrained. Property [productColor] of domain class org.pih.warehouse.product.Product will not be checked during validation.
tomcat_1  | 2021-04-15 02:46:00,372 [localhost-startStop-1] WARN  commons.GrailsDomainConfigurationUtil  - Derived properties may not be constrained. Property [shipmentItemCount] of domain class org.pih.warehouse.shipping.Shipment will not be checked during validation.
tomcat_1  | 2021-04-15 02:46:00,440 [localhost-startStop-1] INFO  validator.Version  - Hibernate Validator 3.1.0.GA
tomcat_1  | 2021-04-15 02:46:00,657 [localhost-startStop-1] INFO  search.HibernateSearchEventListenerRegister  - Unable to find org.hibernate.search.event.FullTextIndexEventListener on the classpath. Hibernate Search is not enabled.
tomcat_1  | 2021-04-15 02:46:01,022 [localhost-startStop-1] INFO  connection.ConnectionProviderFactory  - Initializing connection provider: org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider
tomcat_1  | 2021-04-15 02:46:01,025 [localhost-startStop-1] INFO  cfg.SettingsFactory  - RDBMS: MySQL, version: 5.7.33
tomcat_1  | 2021-04-15 02:46:01,025 [localhost-startStop-1] INFO  cfg.SettingsFactory  - JDBC driver: MySQL Connector Java, version: mysql-connector-java-5.1.47 ( Revision: fe1903b1ecb4a96a917f7ed3190d80c049b1de29 )
tomcat_1  | 2021-04-15 02:46:01,037 [localhost-startStop-1] INFO  dialect.Dialect  - Using dialect: org.hibernate.dialect.MySQL5InnoDBDialect
tomcat_1  | 2021-04-15 02:46:01,051 [localhost-startStop-1] INFO  transaction.TransactionFactoryFactory  - Transaction strategy: org.springframework.orm.hibernate3.SpringTransactionFactory
tomcat_1  | 2021-04-15 02:46:01,056 [localhost-startStop-1] INFO  transaction.TransactionManagerLookupFactory  - No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
tomcat_1  | 2021-04-15 02:46:01,056 [localhost-startStop-1] INFO  cfg.SettingsFactory  - Automatic flush during beforeCompletion(): disabled
tomcat_1  | 2021-04-15 02:46:01,056 [localhost-startStop-1] INFO  cfg.SettingsFactory  - Automatic session close at end of transaction: disabled
tomcat_1  | 2021-04-15 02:46:01,056 [localhost-startStop-1] INFO  cfg.SettingsFactory  - JDBC batch size: 15
tomcat_1  | 2021-04-15 02:46:01,057 [localhost-startStop-1] INFO  cfg.SettingsFactory  - JDBC batch updates for versioned data: disabled
tomcat_1  | 2021-04-15 02:46:01,058 [localhost-startStop-1] INFO  cfg.SettingsFactory  - Scrollable result sets: enabled
tomcat_1  | 2021-04-15 02:46:01,058 [localhost-startStop-1] INFO  cfg.SettingsFactory  - JDBC3 getGeneratedKeys(): enabled
tomcat_1  | 2021-04-15 02:46:01,059 [localhost-startStop-1] INFO  cfg.SettingsFactory  - JDBC result set fetch size: 25
tomcat_1  | 2021-04-15 02:46:01,059 [localhost-startStop-1] INFO  cfg.SettingsFactory  - Connection release mode: auto
tomcat_1  | 2021-04-15 02:46:01,061 [localhost-startStop-1] INFO  cfg.SettingsFactory  - Maximum outer join fetch depth: 2
tomcat_1  | 2021-04-15 02:46:01,061 [localhost-startStop-1] INFO  cfg.SettingsFactory  - Default batch fetch size: 25
tomcat_1  | 2021-04-15 02:46:01,061 [localhost-startStop-1] INFO  cfg.SettingsFactory  - Generate SQL with comments: disabled
tomcat_1  | 2021-04-15 02:46:01,061 [localhost-startStop-1] INFO  cfg.SettingsFactory  - Order SQL updates by primary key: enabled
tomcat_1  | 2021-04-15 02:46:01,061 [localhost-startStop-1] INFO  cfg.SettingsFactory  - Order SQL inserts for batching: enabled
tomcat_1  | 2021-04-15 02:46:01,061 [localhost-startStop-1] INFO  cfg.SettingsFactory  - Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
tomcat_1  | 2021-04-15 02:46:01,073 [localhost-startStop-1] INFO  ast.ASTQueryTranslatorFactory  - Using ASTQueryTranslatorFactory
tomcat_1  | 2021-04-15 02:46:01,073 [localhost-startStop-1] INFO  cfg.SettingsFactory  - Query language substitutions: {}
tomcat_1  | 2021-04-15 02:46:01,073 [localhost-startStop-1] INFO  cfg.SettingsFactory  - JPA-QL strict compliance: disabled
tomcat_1  | 2021-04-15 02:46:01,074 [localhost-startStop-1] INFO  cfg.SettingsFactory  - Second-level cache: disabled
tomcat_1  | 2021-04-15 02:46:01,075 [localhost-startStop-1] INFO  cfg.SettingsFactory  - Query cache: disabled
tomcat_1  | 2021-04-15 02:46:01,075 [localhost-startStop-1] INFO  cfg.SettingsFactory  - Cache region factory : org.hibernate.cache.impl.NoCachingRegionFactory
tomcat_1  | 2021-04-15 02:46:01,076 [localhost-startStop-1] INFO  cfg.SettingsFactory  - Optimize cache for minimal puts: enabled
tomcat_1  | 2021-04-15 02:46:01,076 [localhost-startStop-1] INFO  cfg.SettingsFactory  - Structured second-level cache entries: disabled
tomcat_1  | 2021-04-15 02:46:01,094 [localhost-startStop-1] INFO  cfg.SettingsFactory  - Statistics: disabled
tomcat_1  | 2021-04-15 02:46:01,094 [localhost-startStop-1] INFO  cfg.SettingsFactory  - Deleted entity synthetic identifier rollback: disabled
tomcat_1  | 2021-04-15 02:46:01,094 [localhost-startStop-1] INFO  cfg.SettingsFactory  - Default entity-mode: pojo
tomcat_1  | 2021-04-15 02:46:01,095 [localhost-startStop-1] INFO  cfg.SettingsFactory  - Named query checking : enabled
tomcat_1  | 2021-04-15 02:46:01,189 [localhost-startStop-1] INFO  impl.SessionFactoryImpl  - building session factory
tomcat_1  | 2021-04-15 02:46:04,884 [localhost-startStop-1] INFO  util.NamingHelper  - JNDI InitialContext properties:{}
tomcat_1  | 2021-04-15 02:46:07,110 [localhost-startStop-1] INFO  config.PropertiesFactoryBean  - Loading properties file from class path resource [gsp/views.properties]
tomcat_1  | 2021-04-15 02:46:09,278 [localhost-startStop-1] INFO  ehcache.EhCacheManagerFactoryBean  - Initializing EHCache CacheManager
tomcat_1  | 2021-04-15 02:46:10,957 [localhost-startStop-1] INFO  impl.StdSchedulerFactory  - Using default implementation for ThreadExecutor
tomcat_1  | 2021-04-15 02:46:10,962 [localhost-startStop-1] INFO  simpl.SimpleThreadPool  - Job execution threads will use class loader of thread: localhost-startStop-1
tomcat_1  | 2021-04-15 02:46:10,988 [localhost-startStop-1] INFO  core.SchedulerSignalerImpl  - Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
tomcat_1  | 2021-04-15 02:46:10,988 [localhost-startStop-1] INFO  core.QuartzScheduler  - Quartz Scheduler v.2.1.6 created.
tomcat_1  | 2021-04-15 02:46:10,989 [localhost-startStop-1] INFO  simpl.RAMJobStore  - RAMJobStore initialized.
tomcat_1  | 2021-04-15 02:46:10,990 [localhost-startStop-1] INFO  core.QuartzScheduler  - Scheduler meta-data: Quartz Scheduler (v2.1.6) 'DefaultPluginScheduler' with instanceId 'NON_CLUSTERED'
tomcat_1  |   Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally.
tomcat_1  |   NOT STARTED.
tomcat_1  |   Currently in standby mode.
tomcat_1  |   Number of jobs executed: 0
tomcat_1  |   Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 10 threads.
tomcat_1  |   Using job-store 'org.quartz.simpl.RAMJobStore' - which does not support persistence. and is not clustered.
tomcat_1  |
tomcat_1  | 2021-04-15 02:46:10,991 [localhost-startStop-1] INFO  impl.StdSchedulerFactory  - Quartz scheduler 'DefaultPluginScheduler' initialized from an externally provided properties instance.
tomcat_1  | 2021-04-15 02:46:10,992 [localhost-startStop-1] INFO  impl.StdSchedulerFactory  - Quartz scheduler version: 2.1.6
tomcat_1  | 2021-04-15 02:46:11,008 [localhost-startStop-1] INFO  core.QuartzScheduler  - JobFactory set to: grails.plugin.quartz2.GrailsJobFactory@4e472dfe
tomcat_1  | 2021-04-15 02:46:12,919 [localhost-startStop-1] INFO  support.DefaultLifecycleProcessor  - Starting beans in phase 2147483647
tomcat_1  | Starting Quartz Scheduler in QuartzFactoryBean
tomcat_1  | 2021-04-15 02:46:12,925 [localhost-startStop-1] INFO  core.QuartzScheduler  - Scheduler DefaultPluginScheduler_$_NON_CLUSTERED started.
tomcat_1  | 2021-04-15 02:46:13,748 [localhost-startStop-1] INFO  support.DefaultListableBeanFactory  - Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@5ec6a253: defining beans [org.grails.plugin.zippedresources.ZipResourceMapper,org.grails.plugin.resource.CSSRewriterResourceMapper,org.grails.plugin.cachedresources.HashAndCacheResourceMapper,org.grails.plugin.resource.BundleResourceMapperInstance,org.grails.plugin.resource.CSSRewriterResourceMapperInstance,org.grails.plugin.resource.BundleResourceMapper,org.grails.plugin.cachedresources.HashAndCacheResourceMapperInstance,org.grails.plugin.zippedresources.ZipResourceMapperInstance,org.grails.plugin.resource.CSSPreprocessorResourceMapperInstance,org.grails.plugin.resource.CSSPreprocessorResourceMapper]; parent: org.codehaus.groovy.grails.commons.spring.ReloadAwareAutowireCapableBeanFactory@71aba04b
tomcat_1  | 2021-04-15 02:46:36,239 [localhost-startStop-1] WARN  commons.GrailsDomainConfigurationUtil  - Derived properties may not be constrained. Property [shipmentItemCount] of domain class org.pih.warehouse.shipping.Shipment will not be checked during validation.
tomcat_1  | 2021-04-15 02:46:36,255 [localhost-startStop-1] WARN  commons.GrailsDomainConfigurationUtil  - Derived properties may not be constrained. Property [productColor] of domain class org.pih.warehouse.product.Product will not be checked during validation.
tomcat_1  | 2021-04-15 02:46:36,282 [localhost-startStop-1] WARN  commons.GrailsDomainConfigurationUtil  - Derived properties may not be constrained. Property [monthRequested] of domain class org.pih.warehouse.requisition.Requisition will not be checked during validation.
tomcat_1  | 2021-04-15 02:46:36,283 [localhost-startStop-1] WARN  commons.GrailsDomainConfigurationUtil  - Derived properties may not be constrained. Property [statusSortOrder] of domain class org.pih.warehouse.requisition.Requisition will not be checked during validation.
tomcat_1  | 2021-04-15 02:46:36,590 [localhost-startStop-1] INFO  bootstrap.BootStrap  - Running liquibase changelog(s) ...
tomcat_1  | 2021-04-15 02:46:36,761 [localhost-startStop-1] INFO  bootstrap.BootStrap  - Liquibase running: true
tomcat_1  | 2021-04-15 02:46:36,768 [localhost-startStop-1] INFO  bootstrap.BootStrap  - Setting default schema to openboxes
tomcat_1  | 2021-04-15 02:46:36,768 [localhost-startStop-1] INFO  bootstrap.BootStrap  - Product Version: 5.7.33
tomcat_1  | 2021-04-15 02:46:36,769 [localhost-startStop-1] INFO  bootstrap.BootStrap  - Database Version: 5.7
tomcat_1  | 2021-04-15 02:46:36,781 [localhost-startStop-1] INFO  liquibase  - Reading from `DATABASECHANGELOG`
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | 2021-04-15 02:47:00,094 [DefaultPluginScheduler_Worker-1] INFO  jobs.AssignIdentifierJob  - Postponing job execution until liquibase migrations are complete
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | 2021-04-15 02:48:00,039 [DefaultPluginScheduler_Worker-2] INFO  jobs.AssignIdentifierJob  - Postponing job execution until liquibase migrations are complete
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | 2021-04-15 02:49:00,035 [DefaultPluginScheduler_Worker-3] INFO  jobs.AssignIdentifierJob  - Postponing job execution until liquibase migrations are complete
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | 2021-04-15 02:50:00,019 [DefaultPluginScheduler_Worker-4] INFO  jobs.AssignIdentifierJob  - Postponing job execution until liquibase migrations are complete
tomcat_1  | 2021-04-15 02:50:00,096 [DefaultPluginScheduler_Worker-5] INFO  jobs.DataCleaningJob  - Postponing job execution until liquibase migrations are complete
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | 2021-04-15 02:51:00,016 [DefaultPluginScheduler_Worker-6] INFO  jobs.AssignIdentifierJob  - Postponing job execution until liquibase migrations are complete
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | 2021-04-15 02:51:37,574 [localhost-startStop-1] ERROR context.ContextLoader  - Context initialization failed
tomcat_1  | org.springframework.beans.factory.access.BootstrapException: Error executing bootstraps; nested exception is org.codehaus.groovy.runtime.InvokerInvocationException: liquibase.exception.LockException: Could not acquire change log lock.  Currently locked by cc00162cc99a (172.28.0.2) since 4/15/21 12:02 AM
tomcat_1  |     at org.codehaus.groovy.grails.web.context.GrailsContextLoader.createWebApplicationContext(GrailsContextLoader.java:87)
tomcat_1  |     at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:197)
tomcat_1  |     at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:47)
tomcat_1  |     at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:5197)
tomcat_1  |     at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5720)
tomcat_1  |     at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:145)
tomcat_1  |     at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:1018)
tomcat_1  |     at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:994)
tomcat_1  |     at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:652)
tomcat_1  |     at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:1127)
tomcat_1  |     at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:2020)
tomcat_1  |     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:473)
tomcat_1  |     at java.util.concurrent.FutureTask.run(FutureTask.java:262)
tomcat_1  |     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1152)
tomcat_1  |     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:622)
tomcat_1  |     at java.lang.Thread.run(Thread.java:748)
tomcat_1  | Caused by: org.codehaus.groovy.runtime.InvokerInvocationException: liquibase.exception.LockException: Could not acquire change log lock.  Currently locked by cc00162cc99a (172.28.0.2) since 4/15/21 12:02 AM
tomcat_1  |     at grails.util.Environment.evaluateEnvironmentSpecificBlock(Environment.java:251)
tomcat_1  |     at grails.util.Environment.executeForEnvironment(Environment.java:244)
tomcat_1  |     at grails.util.Environment.executeForCurrentEnvironment(Environment.java:220)
tomcat_1  |     ... 5 more
tomcat_1  | Caused by: liquibase.exception.LockException: Could not acquire change log lock.  Currently locked by cc00162cc99a (172.28.0.2) since 4/15/21 12:02 AM
tomcat_1  |     at liquibase.lock.LockHandler.waitForLock(LockHandler.java:170)
tomcat_1  |     at liquibase.Liquibase.update(Liquibase.java:100)
tomcat_1  |     at liquibase.Liquibase$update.call(Unknown Source)
tomcat_1  |     at BootStrap$_closure1.doCall(BootStrap.groovy:447)
tomcat_1  |     ... 8 more
tomcat_1  | Apr 15, 2021 2:51:37 AM org.apache.catalina.core.StandardContext startInternal
tomcat_1  | SEVERE: One or more listeners failed to start. Full details will be found in the appropriate container log file
tomcat_1  | Apr 15, 2021 2:51:37 AM org.apache.catalina.core.StandardContext startInternal
tomcat_1  | SEVERE: Context [/openboxes] startup failed due to previous errors
tomcat_1  | Apr 15, 2021 2:51:37 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesJdbc
tomcat_1  | SEVERE: The web application [/openboxes] registered the JDBC driver [com.mysql.jdbc.Driver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
tomcat_1  | Apr 15, 2021 2:51:37 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [C3P0PooledConnectionPoolManager[identityToken->1br5hqbag1mntn62fe84fb|2abaa1d8]-AdminTaskTimer] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:37 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [C3P0PooledConnectionPoolManager[identityToken->1br5hqbag1mntn62fe84fb|2abaa1d8]-HelperThread-#0] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:37 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [C3P0PooledConnectionPoolManager[identityToken->1br5hqbag1mntn62fe84fb|2abaa1d8]-HelperThread-#1] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:37 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [C3P0PooledConnectionPoolManager[identityToken->1br5hqbag1mntn62fe84fb|2abaa1d8]-HelperThread-#2] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:37 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [C3P0PooledConnectionPoolManager[identityToken->1br5hqbag1mntn62fe84fb|2abaa1d8]-DeferredStatementDestroyerThread-#0] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:37 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [Abandoned connection cleanup thread] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:37 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [net.sf.ehcache.CacheManager@68f4c6c8] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:37 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [Store dashboardCache Spool Thread] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:37 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [Store messageCache Spool Thread] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:37 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [Store dashboardTotalStockValueCache Spool Thread] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [Store dashboardProductSummaryCache Spool Thread] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [Store fastMoversCache Spool Thread] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [Store quantityOnHandCache Spool Thread] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [Store binLocationSummaryCache Spool Thread] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [Store inventorySnapshotCache Spool Thread] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [Store megamenuCache Spool Thread] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [Store selectTagsCache Spool Thread] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [DefaultPluginScheduler_Worker-1] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [DefaultPluginScheduler_Worker-2] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [DefaultPluginScheduler_Worker-3] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [DefaultPluginScheduler_Worker-4] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [DefaultPluginScheduler_Worker-5] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [DefaultPluginScheduler_Worker-6] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [DefaultPluginScheduler_Worker-7] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [DefaultPluginScheduler_Worker-8] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [DefaultPluginScheduler_Worker-9] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [DefaultPluginScheduler_Worker-10] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [Store binLocationReportCache Spool Thread] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [Store selectCatalogsCache Spool Thread] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [Store inventoryBrowserCache Spool Thread] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [Store selectTagCache Spool Thread] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [Store selectCategoryCache Spool Thread] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [Store dashboardGenericProductSummaryCache Spool Thread] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [Timer-0] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
tomcat_1  | SEVERE: The web application [/openboxes] appears to have started a thread named [DefaultPluginScheduler_QuartzSchedulerThread] but has failed to stop it. This is very likely to create a memory leak.
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.startup.HostConfig deployWAR
tomcat_1  | INFO: Deployment of web application archive /usr/local/tomcat/webapps/openboxes.war has finished in 381,466 ms
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.startup.HostConfig deployDirectory
tomcat_1  | INFO: Deploying web application directory /usr/local/tomcat/webapps/manager
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.startup.HostConfig deployDirectory
tomcat_1  | INFO: Deployment of web application directory /usr/local/tomcat/webapps/manager has finished in 254 ms
tomcat_1  | Apr 15, 2021 2:51:38 AM org.apache.catalina.startup.HostConfig deployDirectory
tomcat_1  | INFO: Deploying web application directory /usr/local/tomcat/webapps/examples
tomcat_1  | Apr 15, 2021 2:51:40 AM org.apache.catalina.startup.HostConfig deployDirectory
tomcat_1  | INFO: Deployment of web application directory /usr/local/tomcat/webapps/examples has finished in 2,166 ms
tomcat_1  | Apr 15, 2021 2:51:40 AM org.apache.catalina.startup.HostConfig deployDirectory
tomcat_1  | INFO: Deploying web application directory /usr/local/tomcat/webapps/docs
tomcat_1  | Apr 15, 2021 2:51:40 AM org.apache.catalina.startup.HostConfig deployDirectory
tomcat_1  | INFO: Deployment of web application directory /usr/local/tomcat/webapps/docs has finished in 109 ms
tomcat_1  | Apr 15, 2021 2:51:40 AM org.apache.catalina.startup.HostConfig deployDirectory
tomcat_1  | INFO: Deploying web application directory /usr/local/tomcat/webapps/ROOT
tomcat_1  | Apr 15, 2021 2:51:40 AM org.apache.catalina.startup.HostConfig deployDirectory
tomcat_1  | INFO: Deployment of web application directory /usr/local/tomcat/webapps/ROOT has finished in 113 ms
tomcat_1  | Apr 15, 2021 2:51:40 AM org.apache.catalina.startup.HostConfig deployDirectory
tomcat_1  | INFO: Deploying web application directory /usr/local/tomcat/webapps/host-manager
tomcat_1  | Apr 15, 2021 2:51:40 AM org.apache.catalina.startup.HostConfig deployDirectory
tomcat_1  | INFO: Deployment of web application directory /usr/local/tomcat/webapps/host-manager has finished in 67 ms
tomcat_1  | Apr 15, 2021 2:51:40 AM org.apache.coyote.AbstractProtocol start
tomcat_1  | INFO: Starting ProtocolHandler ["http-apr-8080"]
tomcat_1  | Apr 15, 2021 2:51:40 AM org.apache.coyote.AbstractProtocol start
tomcat_1  | INFO: Starting ProtocolHandler ["ajp-apr-8009"]
tomcat_1  | Apr 15, 2021 2:51:40 AM org.apache.catalina.startup.Catalina start
tomcat_1  | INFO: Server startup in 384757 ms
tomcat_1  | Apr 15, 2021 2:51:41 AM org.apache.catalina.loader.WebappClassLoaderBase findResourceInternal
tomcat_1  | INFO: Illegal access: this web application instance has been stopped already.  Could not load .  The eventual following stack trace is caused by an error thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access, and has no functional impact.
tomcat_1  | log4j:WARN No appenders could be found for logger (grails.app.job.org.pih.warehouse.jobs.AssignIdentifierJob).
tomcat_1  | log4j:WARN Please initialize the log4j system properly.
tomcat_1  | log4j:WARN See http:https://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.

@jmiranda
Copy link
Member

Ok, great. This is what I was assuming had happened.

tomcat_1  | 2021-04-15 02:46:36,590 [localhost-startStop-1] INFO  bootstrap.BootStrap  - Running liquibase changelog(s) ...
tomcat_1  | 2021-04-15 02:46:36,761 [localhost-startStop-1] INFO  bootstrap.BootStrap  - Liquibase running: true
tomcat_1  | 2021-04-15 02:46:36,768 [localhost-startStop-1] INFO  bootstrap.BootStrap  - Setting default schema to openboxes
tomcat_1  | 2021-04-15 02:46:36,768 [localhost-startStop-1] INFO  bootstrap.BootStrap  - Product Version: 5.7.33
tomcat_1  | 2021-04-15 02:46:36,769 [localhost-startStop-1] INFO  bootstrap.BootStrap  - Database Version: 5.7
tomcat_1  | 2021-04-15 02:46:36,781 [localhost-startStop-1] INFO  liquibase  - Reading from `DATABASECHANGELOG`
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....
tomcat_1  | Waiting for changelog lock....

This means that the database migrations were interrupted before they completed (probably because you weren't expecting the initial startup to take so long) and so there's a "lock" record in the Liquibase DATABASECHANGELOGLOCK table. You need to connect to the MySQL service and delete that record. Then restart the containers and wait for all database migrations to be executed.

There are probably a few different ways to do that (ssh into the container or mysql in via the externally exposed port) but here's a

  1. Find the port exposed by the MySQL service
[jmiranda@jmiranda-ThinkPad-W540 ~]$ docker ps
CONTAINER ID        IMAGE               COMMAND                  CREATED             STATUS              PORTS                    NAMES
bf7936214fee        tomcat:7            "catalina.sh run"        7 hours ago         Up 2 minutes        0.0.0.0:8072->8080/tcp   docker_tomcat_1
8ac735977d9c        mysql:5.7           "docker-entrypoint.s…"   7 hours ago         Up 2 minutes        3306/tcp, 33060/tcp      docker_db_1
  1. Connect to MySQL through that port
[jmiranda@jmiranda-ThinkPad-W540 ~]$ mysql -u root -p openboxes --port 33060 
Enter password: 
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 5499
Server version: 5.7.33-0ubuntu0.18.04.1 (Ubuntu)

Copyright (c) 2000, 2021, Oracle and/or its affiliates.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
  1. Check the DATABASECHANGELOGLOCK table
mysql> select * from DATABASECHANGELOGLOCK;
+----+--------+-------------+----------+
| ID | LOCKED | LOCKGRANTED | LOCKEDBY |
+----+--------+-------------+----------+
|  1 |        | NULL        | NULL     |
+----+--------+-------------+----------+
1 row in set (0.00 sec)
  1. Delete the lock record
mysql> delete from DATABASECHANGELOGLOCK;
Query OK, 1 row affected (0.00 sec)

@ghost
Copy link
Author

ghost commented Apr 15, 2021

Thanks for your advice.
I was able to get it to work without any problems.

This issue was closed.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant