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

Docker build fails #91

Open
vidboda opened this issue Mar 7, 2023 · 65 comments
Open

Docker build fails #91

vidboda opened this issue Mar 7, 2023 · 65 comments

Comments

@vidboda
Copy link

vidboda commented Mar 7, 2023

Hi,

was trying to update my VV docker - I deleted all the containers according to DOCKER.md to start from scratch.
I cloned the current vv repo, then added my NCBI key and then launched the build affter having pulled
docker-compose build --no-cache

and I got the following error:

root@restvv:~/rest_variantValidator# docker-compose pull
Pulling vdb     ... done
Pulling vvta    ... done
Pulling seqrepo ... done
Pulling restvv  ... done
root@restvv:~/rest_variantValidator# docker-compose build --no-cache
Building vdb
Sending build context to Docker daemon  2.815MB
Step 1/7 : FROM mysql:5.7
5.7: Pulling from library/mysql
e048d0a38742: Pull complete 
c7847c8a41cb: Pull complete 
351a550f260d: Pull complete 
8ce196d9d34f: Pull complete 
17febb6f2030: Pull complete 
d4e426841fb4: Pull complete 
fda41038b9f8: Pull complete 
f47aac56b41b: Pull complete 
a4a90c369737: Pull complete 
97091252395b: Pull complete 
84fac29d61e9: Pull complete 
Digest: sha256:8cf035b14977b26f4a47d98e85949a7dd35e641f88fc24aa4b466b36beecf9d6
Status: Downloaded newer image for mysql:5.7
 ---> be16cf2d832a
Step 2/7 : ENV MYSQL_RANDOM_ROOT_PASSWORD yes
 ---> Running in 3c1a4ec16089
Removing intermediate container 3c1a4ec16089
 ---> 144776638a76
Step 3/7 : ENV MYSQL_DATABASE validator
 ---> Running in 5a9c9ad716f3
Removing intermediate container 5a9c9ad716f3
 ---> 27cfe835cf01
Step 4/7 : ENV MYSQL_USER vvadmin
 ---> Running in 9641e3b4c58b
Removing intermediate container 9641e3b4c58b
 ---> 1d5458209762
Step 5/7 : ENV MYSQL_PASSWORD var1ant
 ---> Running in 171c9455c99c
Removing intermediate container 171c9455c99c
 ---> a73e612eb1d0
Step 6/7 : RUN apt-get update && apt-get install -y wget && rm -rf /var/lib/apt/lists/*
 ---> Running in 9a7cb1a7ddea
/bin/sh: apt-get: command not found
The command '/bin/sh -c apt-get update && apt-get install -y wget && rm -rf /var/lib/apt/lists/*' returned a non-zero code: 127
ERROR: Service 'vdb' failed to build : Build failed

Does that ring a bell to you?
thx

@vidboda
Copy link
Author

vidboda commented Mar 8, 2023

it seems that you need to explicitely call for the mysql debian image, or change the package manager from apt-get to yum.

The simplest is likely to change in vdb_docker.df the line:

FROM mysql:5.7

to

FROM mysql:5.7-debian

@vidboda
Copy link
Author

vidboda commented Mar 8, 2023

ok the build process seems to be ok, but launch fails.

I followed the following steps to recreate the containers and update the code:

# cd /root/rest_variantValidator
# docker-compose down
# docker-compose rm
# docker system prune -a --volumes
# mkdir ~/variantvalidator_data/share/logs
# git stash
# git pull

added email and NCBI API KEY in docker.ini, then I had to slightly modify vdb_docker.df

mysql:5.7

becomes

mysql:5.7-debian

and

apt-get update && apt-get install -y wget && rm -rf /var/lib/apt/lists/*

becomes

RUN apt-key adv --keyserver hkp://keyserver.ubuntu.com --recv-keys 467B942D3A79BD29 && apt-get update && apt-get install -y wget && rm -rf /var/lib/apt/lists/*

then:

# rm -r -f ~/variantvalidator_data/share/seqrepo/*
# docker-compose build --no-cache
# docker-compose up vvta
Ctrl-C when done
# docker-compose up vdb
Ctrl-C when done
# docker-compose up seqrepo
# docker-compose up -d                                                                       
Starting rest_variantvalidator_seqrepo_1 ... done                                                                               
Starting rest_variantvalidator_vvta_1    ... done                                                                                                                                                                                                                
Starting rest_variantvalidator_vdb_1     ... done                                                                               
Starting rest_variantvalidator_restvv_1  ... done 
# docker-compose up
Starting rest_variantvalidator_vvta_1    ... done
Starting rest_variantvalidator_seqrepo_1 ... done
Starting rest_variantvalidator_vdb_1     ... done
Starting rest_variantvalidator_restvv_1  ... done
Attaching to rest_variantvalidator_seqrepo_1, rest_variantvalidator_vdb_1, rest_variantvalidator_vvta_1, rest_variantvalidator_restvv_1
vdb_1      | 2023-03-08 11:09:51+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 5.7.41-1debian10 started.
vdb_1      | 2023-03-08 11:09:52+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
vvta_1     | 
vvta_1     | PostgreSQL Database directory appears to contain a database; Skipping initialization
vvta_1     | 
vdb_1      | 2023-03-08 11:09:52+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 5.7.41-1debian10 started.
rest_variantvalidator_seqrepo_1 exited with code 0
vdb_1      | 2023-03-08T11:09:52.615513Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
vdb_1      | 2023-03-08T11:09:52.617419Z 0 [Note] mysqld (mysqld 5.7.41) starting as process 1 ...
vdb_1      | 2023-03-08T11:09:52.620318Z 0 [Note] InnoDB: PUNCH HOLE support available
vdb_1      | 2023-03-08T11:09:52.620345Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
vdb_1      | 2023-03-08T11:09:52.620349Z 0 [Note] InnoDB: Uses event mutexes
vdb_1      | 2023-03-08T11:09:52.620351Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
vdb_1      | 2023-03-08T11:09:52.620353Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.12
vdb_1      | 2023-03-08T11:09:52.620356Z 0 [Note] InnoDB: Using Linux native AIO
vdb_1      | 2023-03-08T11:09:52.620721Z 0 [Note] InnoDB: Number of pools: 1
vvta_1     | 2023-03-08 11:09:52.175 UTC [1] LOG:  starting PostgreSQL 12.6 (Debian 12.6-1.pgdg100+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 8.3.0-6) 8.3.0, 64-bit
vvta_1     | 2023-03-08 11:09:52.175 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
vvta_1     | 2023-03-08 11:09:52.175 UTC [1] LOG:  listening on IPv6 address "::", port 5432
vvta_1     | 2023-03-08 11:09:53.072 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
vdb_1      | 2023-03-08T11:09:52.620857Z 0 [Note] InnoDB: Using CPU crc32 instructions
vvta_1     | 2023-03-08 11:09:53.451 UTC [26] LOG:  database system was shut down at 2023-03-08 11:09:42 UTC
vdb_1      | 2023-03-08T11:09:52.623424Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
vvta_1     | 2023-03-08 11:09:53.461 UTC [1] LOG:  database system is ready to accept connections
vdb_1      | 2023-03-08T11:09:52.631368Z 0 [Note] InnoDB: Completed initialization of buffer pool
vdb_1      | 2023-03-08T11:09:52.633988Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
vdb_1      | 2023-03-08T11:09:52.647019Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
vdb_1      | 2023-03-08T11:09:53.055476Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
vdb_1      | 2023-03-08T11:09:53.055605Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
vdb_1      | 2023-03-08T11:09:53.426302Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
vdb_1      | 2023-03-08T11:09:53.427350Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
vdb_1      | 2023-03-08T11:09:53.427377Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
vdb_1      | 2023-03-08T11:09:53.428404Z 0 [Note] InnoDB: Waiting for purge to start
vdb_1      | 2023-03-08T11:09:53.478778Z 0 [Note] InnoDB: 5.7.41 started; log sequence number 230398356
vdb_1      | 2023-03-08T11:09:53.479609Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
vdb_1      | 2023-03-08T11:09:53.479857Z 0 [Note] Plugin 'FEDERATED' is disabled.
vdb_1      | 2023-03-08T11:09:53.480899Z 0 [Note] InnoDB: Buffer pool(s) load completed at 230308 11:09:53
vdb_1      | 2023-03-08T11:09:53.486670Z 0 [Note] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.
vdb_1      | 2023-03-08T11:09:53.486869Z 0 [Note] Skipping generation of SSL certificates as certificate files are present in data directory.
vdb_1      | 2023-03-08T11:09:53.486962Z 0 [Warning] A deprecated TLS version TLSv1 is enabled. Please use TLSv1.2 or higher.
vdb_1      | 2023-03-08T11:09:53.486985Z 0 [Warning] A deprecated TLS version TLSv1.1 is enabled. Please use TLSv1.2 or higher.
vdb_1      | 2023-03-08T11:09:53.487623Z 0 [Warning] CA certificate ca.pem is self signed.
vdb_1      | 2023-03-08T11:09:53.487778Z 0 [Note] Skipping generation of RSA key pair as key files are present in data directory.
vdb_1      | 2023-03-08T11:09:53.488444Z 0 [Note] Server hostname (bind-address): '*'; port: 3306
vdb_1      | 2023-03-08T11:09:53.488606Z 0 [Note] IPv6 is available.
vdb_1      | 2023-03-08T11:09:53.488696Z 0 [Note]   - '::' resolves to '::';
vdb_1      | 2023-03-08T11:09:53.488796Z 0 [Note] Server socket created on IP: '::'.
vdb_1      | 2023-03-08T11:09:53.494529Z 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.
vdb_1      | 2023-03-08T11:09:53.504179Z 0 [Note] Event Scheduler: Loaded 0 events
vdb_1      | 2023-03-08T11:09:53.504489Z 0 [Note] mysqld: ready for connections.
vdb_1      | Version: '5.7.41'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  MySQL Community Server (GPL)
restvv_1   | [2023-03-08 11:09:54 +0000] [7] [INFO] Starting gunicorn 20.1.0
restvv_1   | [2023-03-08 11:09:54 +0000] [7] [INFO] Listening at: http://0.0.0.0:8000 (7)
restvv_1   | [2023-03-08 11:09:54 +0000] [7] [INFO] Using worker: gthread
restvv_1   | [2023-03-08 11:09:54 +0000] [8] [INFO] Booting worker with pid: 8
restvv_1   | Exception ignored in: <function UTA_postgresql.__del__ at 0x7f3c19daf6d0>
restvv_1   | Traceback (most recent call last):
restvv_1   |   File "/usr/local/lib/python3.10/site-packages/vvhgvs/dataproviders/uta.py", line 515, in __del__
restvv_1   |     self.close()
restvv_1   |   File "/usr/local/lib/python3.10/site-packages/vvhgvs/dataproviders/uta.py", line 519, in close
restvv_1   |     self._pool.closeall()
restvv_1   | AttributeError: 'UTA_postgresql' object has no attribute '_pool'
restvv_1   | [2023-03-08 11:09:54 +0000] [7] [INFO] Shutting down: Master
restvv_1   | [2023-03-08 11:09:54 +0000] [7] [INFO] Reason: Worker failed to boot.
rest_variantvalidator_restvv_1 exited with code 3

Then rest_variantvalidator_restvv_1 fails to launch.

I retried with the following end sequence and code from rest_variantValidator release 2.2.0 instead of just cloning the repo or pulling new code, but same error at startup:

# docker-compose up vvta
Ctrl-C when done
# docker-compose up vdb
Ctrl-C when done
# docker-compose up

Any help would be highly appreciated.

@ifokkema
Copy link

I'm no expert on Docker (actually, I rarely use it), but I remember changes have been made recently about whether or not VV had to use pooling of database connections. Remember those race conditions that we saw? The error is about this file. It seems that perhaps UTA is confused about whether to use pooling or not. Do you think you have write access to /usr/local/lib/python3.10/site-packages/vvhgvs/dataproviders/uta.py? If so, you could edit the code to fix that bug.

@vidboda
Copy link
Author

vidboda commented Mar 14, 2023

Thx @ifokkema,

however, the code on this file looks good to me, as far as I can tell.

In def connect(), if pooling is enabled, the object is correctly instanciated:

if self.pooling:
    _logger.info("Using UTA ThreadedConnectionPool")
    self._pool = psycopg2.pool.ThreadedConnectionPool(vvhgvs.global_config.uta.pool_min,
                                                              vvhgvs.global_config.uta.pool_max, **conn_args)

then self._pool should be accessible when closing:

def close(self):
        if self.pooling:
            self._pool.closeall() 

Then I'm not sure of what is wrong here. Or maybe the pooling attribute has changed after the first connection, from False to True? That would be weird. And the code is 2 yaers old. Well...

@ifokkema
Copy link

I didn't mean that the bug is necessarily in this file; it might as well be in its usage outside of this file. I don't see self.pooling set other than at the time the class is created, so it's possible that external code modifies the variable. Also, external code could have resulted in the loss of the self._pool variable. Either way, the error indicates pooling is true while self._pool isn't set. Checking for self._pool as well as self.pooling will likely remove the error, although indeed, it may not actually fix the origin of the bug. So while in the long run, the bug should properly be fixed, right now, you could perhaps modify the code such that the error is avoided.

@vidboda
Copy link
Author

vidboda commented Mar 14, 2023

well, you're probably right, as usual, but in my opinion just checking could lead to improper closing of the connection, or worse, to leave it open which would quickly result in a freeze of the whole system due to a lack of available connections. I'll maybe make some tests tomorrow. thanks anyway.

@ifokkema
Copy link

Well, the connection, if it exists, will still be closed, of course. The else will simply take care of it.

Anyway, in the worst-case scenario, the connection should close when the Python program ends.

@vidboda
Copy link
Author

vidboda commented Mar 14, 2023

ok I'll give it a try asap with a try/except block

Well, the connection, if it exists, will still be closed, of course. The else will simply take care of it.

But I wouldn't bet on it. From my experience, depending on the way you handle psycopg2 connections, the syntax differs then if a connection is opened with a connexion pool you must release it the same way - then the else may fail as well. But it may work if the self.pooling boolean has been modify in the meantime, right.

Anyway, in the worst-case scenario, the connection should close when the Python program ends.

again, not sure about that, even if it seems good sense. I've had the case in a flask app where connections were not correctly closed, and when ran as a wsgi app, connections remained opened, and eventually led to the system freeze. Apache kind of keeps the scripts in memory, to be able to execute them quicker (such as in mod_perl, for example). You probably know better on this.

@ifokkema
Copy link

ok I'll give it a try asap with a try/except block

That may actually lead to the connection not being closed, as the else will never get executed. If you just adapt the if, the else will be run if there's no pool to close.

Well, the connection, if it exists, will still be closed, of course. The else will simply take care of it.

But I wouldn't bet on it. From my experience, depending on the way you handle psycopg2 connections, the syntax differs then if a connection is opened with a connexion pool you must release it the same way - then the else may fail as well.

Sure, but there's nothing to release as there is no self._pool. So, unless self._pool has been removed, the connection was never pooled. And the else is sufficiently protected against failure as it checks if there is a connection at all.

But it may work if the self.pooling boolean has been modify in the meantime, right.

That's my guess, indeed, but only a guess. It may also be that the connection has already closed and self._pool got removed.

Anyway, in the worst-case scenario, the connection should close when the Python program ends.

again, not sure about that, even if it seems good sense. I've had the case in a flask app where connections were not correctly closed, and when ran as a wsgi app, connections remained opened, and eventually led to the system freeze. Apache kind of keeps the scripts in memory, to be able to execute them quicker (such as in mod_perl, for example). You probably know better on this.

Well, I hardly use WSGI, so I wouldn't know better, actually... I just quickly googled my assumption that the connections would be closed, the first link mentioned that indeed this would happen, and I didn't look further. So you might be right there! Either way, it's worth a shot, as now, nothing is working.

@Peter-J-Freeman
Copy link
Contributor

@beboche @ifokkema

I have updated the docker with mysql:5.7-debian

AttributeError: 'UTA_postgresql' object has no attribute '_pool'
Have seen this before. Think it is when VVTA fails to connect.

I'll see if I can build the container at my end

@vidboda
Copy link
Author

vidboda commented Apr 19, 2023

Nice I'll give it a try asap

@Peter-J-Freeman
Copy link
Contributor

One sec. forgot to add it to the API. Doing now

@vidboda
Copy link
Author

vidboda commented Apr 19, 2023 via email

@vidboda
Copy link
Author

vidboda commented Apr 19, 2023

@Peter-J-Freeman is it ok from your side?

@Peter-J-Freeman
Copy link
Contributor

I ran it this afternoon and everything installed.

@vidboda
Copy link
Author

vidboda commented Apr 19, 2023

fails for me when docker-compose up (last step of update) - followed the Docker.md instructions, last step:

root@restvv:~/rest_variantValidator# docker-compose up
Starting rest_variantvalidator_vvta_1    ... done
Starting rest_variantvalidator_vdb_1     ... done
Creating rest_variantvalidator_seqrepo_1 ... 
Creating rest_variantvalidator_restvv_1  ... done

ERROR: for rest_variantvalidator_seqrepo_1  UnixHTTPConnectionPool(host='localhost', port=None): Read timed out. (read timeout=60)

ERROR: for seqrepo  UnixHTTPConnectionPool(host='localhost', port=None): Read timed out. (read timeout=60)
ERROR: An HTTP request took too long to complete. Retry with --verbose to obtain debug information.
If you encounter this issue regularly because of slow network conditions, consider setting COMPOSE_HTTP_TIMEOUT to a higher value (current value: 60).

seems to come from me but the server looks fine

@vidboda
Copy link
Author

vidboda commented Apr 19, 2023

It's a debian 11 VM - when I launch back the last snapshot, everything runs fine with:

VariantValidator version 2.1.1.dev2+g294fd63
VariantFormatter version 2.1.0
vv_hgvs version 2.0.2.dev1+g6ecbf8e
VVTA release vvta_2022_02
vvSeqRepo release VV_SR_2022_02

@Peter-J-Freeman
Copy link
Contributor

So you are seeing errors but everything runs?

@vidboda
Copy link
Author

vidboda commented Apr 20, 2023

no sorry. I've got a VM running legacy VV. I want to update.
The update runs fine following the Docker.md instructions, except the last step docker-compose up where seqrepo does not start properly.
I'll try again today, rebuilding everything.

@vidboda
Copy link
Author

vidboda commented Apr 20, 2023

I don't know what's going on.
I built this morning a brand new VM running alma linux 9 with 24 Go Ram (up to 32Go).
I ran an OS update then installed docker 23.0.4 and docker-compose 2.17.2.

I then exactly followed the docker.md instructions.

Everything's fine until the second last step (building vdb), which seems to somewhat fail:

$ docker-compose up vdb
...
rest_variantvalidator-vdb-1  | 2023-04-20T14:19:23.223265Z 0 [Note] InnoDB: 5.7.42 started; log sequence number 2767280
rest_variantvalidator-vdb-1  | 2023-04-20T14:19:23.223579Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
rest_variantvalidator-vdb-1  | 2023-04-20T14:19:23.223776Z 0 [Note] Plugin 'FEDERATED' is disabled.
rest_variantvalidator-vdb-1  | 2023-04-20T14:19:23.229409Z 0 [Note] InnoDB: Buffer pool(s) load completed at 230420 14:19:23
rest_variantvalidator-vdb-1  | 2023-04-20T14:19:23.241015Z 0 [Note] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.
rest_variantvalidator-vdb-1  | 2023-04-20T14:19:23.241332Z 0 [Note] Skipping generation of SSL certificates as certificate files are present in data directory.
rest_variantvalidator-vdb-1  | 2023-04-20T14:19:23.241429Z 0 [Warning] A deprecated TLS version TLSv1 is enabled. Please use TLSv1.2 or higher.
rest_variantvalidator-vdb-1  | 2023-04-20T14:19:23.241437Z 0 [Warning] A deprecated TLS version TLSv1.1 is enabled. Please use TLSv1.2 or higher.
rest_variantvalidator-vdb-1  | 2023-04-20T14:19:23.242244Z 0 [Warning] CA certificate ca.pem is self signed.
rest_variantvalidator-vdb-1  | 2023-04-20T14:19:23.242387Z 0 [Note] Skipping generation of RSA key pair as key files are present in data directory.
rest_variantvalidator-vdb-1  | 2023-04-20T14:19:23.266104Z 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.
rest_variantvalidator-vdb-1  | 2023-04-20T14:19:23.275399Z 0 [Note] Event Scheduler: Loaded 0 events
rest_variantvalidator-vdb-1  | 2023-04-20T14:19:23.280145Z 0 [Note] mysqld: ready for connections.
rest_variantvalidator-vdb-1  | Version: '5.7.42'  socket: '/var/run/mysqld/mysqld.sock'  port: 0  MySQL Community Server (GPL)
rest_variantvalidator-vdb-1  | 2023-04-20 14:19:24+00:00 [Note] [Entrypoint]: Temporary server started.
rest_variantvalidator-vdb-1  | ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111)
rest_variantvalidator-vdb-1  | /usr/local/bin/docker-entrypoint.sh: line 282:   125 Killed                  "$@" --skip-networking --default-time-zone=SYSTEM --socket="${SOCKET}"
rest_variantvalidator-vdb-1 exited with code 1

Then if I try the last command, this is the restvv container that fails the same than on my previous machine:

# docker-compose up                                                            
[+] Running 4/4                                                                                                                 
 ✔ Container rest_variantvalidator-seqrepo-1  Created                                                                                                                                                                                              82.7s         
 ✔ Container rest_variantvalidator-vvta-1     Created                                                                                                                                                                                               0.0s         
 ✔ Container rest_variantvalidator-vdb-1      Created                                                                                                                                                                                               0.0s         
 ✔ Container rest_variantvalidator-restvv-1   Created                                                                                                                                                                                               0.4s         
Attaching to rest_variantvalidator-restvv-1, rest_variantvalidator-seqrepo-1, rest_variantvalidator-vdb-1, rest_variantvalidator-vvta-1                                                                                                                          
rest_variantvalidator-vdb-1      | 2023-04-20 14:23:55+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 5.7.42-1debian10 started.                                                                                                                   
rest_variantvalidator-vvta-1     |                                                                                              
rest_variantvalidator-vvta-1     | PostgreSQL Database directory appears to contain a database; Skipping initialization                                                                                                                                          
rest_variantvalidator-vvta-1     |                                                                                              
rest_variantvalidator-seqrepo-1 exited with code 0                                                                                                                                                                                                               
rest_variantvalidator-vvta-1     | 2023-04-20 14:23:55.985 UTC [1] LOG:  starting PostgreSQL 12.6 (Debian 12.6-1.pgdg100+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 8.3.0-6) 8.3.0, 64-bit                                                               
rest_variantvalidator-vvta-1     | 2023-04-20 14:23:55.987 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432         
rest_variantvalidator-vvta-1     | 2023-04-20 14:23:55.987 UTC [1] LOG:  listening on IPv6 address "::", port 5432                                                                                                                                               
rest_variantvalidator-vvta-1     | 2023-04-20 14:23:56.033 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"                                                                                                                            
rest_variantvalidator-vvta-1     | 2023-04-20 14:23:56.126 UTC [27] LOG:  database system was shut down at 2023-04-20 14:02:37 UTC                                                                                                                               
rest_variantvalidator-vvta-1     | 2023-04-20 14:23:56.201 UTC [1] LOG:  database system is ready to accept connections                                                                                                                                          
rest_variantvalidator-restvv-1   | [2023-04-20 14:23:57 +0000] [7] [INFO] Starting gunicorn 20.1.0                                                                                                                                                               
rest_variantvalidator-restvv-1   | [2023-04-20 14:23:57 +0000] [7] [INFO] Listening at: http://0.0.0.0:8000 (7)                                                                                                                                                  
rest_variantvalidator-restvv-1   | [2023-04-20 14:23:57 +0000] [7] [INFO] Using worker: gthread                                                                                                                                                                  
rest_variantvalidator-restvv-1   | [2023-04-20 14:23:57 +0000] [8] [INFO] Booting worker with pid: 8                            
rest_variantvalidator-restvv-1   | Exception ignored in: <function Mixin.__del__ at 0x7f1c90097d90>                                                                                                                                                              
rest_variantvalidator-restvv-1   | Traceback (most recent call last):                                                                                                                                                                                            
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/VariantValidator/modules/vvMixinInit.py", line 213, in __del__                                                                                                                
rest_variantvalidator-restvv-1   |     del self.db                                                                              
rest_variantvalidator-restvv-1   | AttributeError: db                                                                                                                                                                                                            
rest_variantvalidator-restvv-1   | [2023-04-20 14:23:58 +0000] [7] [INFO] Shutting down: Master                                 
rest_variantvalidator-restvv-1   | [2023-04-20 14:23:58 +0000] [7] [INFO] Reason: Worker failed to boot.                                                                                                                                                         
rest_variantvalidator-restvv-1 exited with code 3   
...

Note: I am able to run again quite successfully

docker-compose up vdb

(no error), but

docker-compose up

fails the same:

rest_variantvalidator-restvv-1   | Exception ignored in: <function Mixin.__del__ at 0x7ffbc72880d0>
rest_variantvalidator-restvv-1   | Traceback (most recent call last):
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/VariantValidator/modules/vvMixinInit.py", line 213, in __del__
rest_variantvalidator-restvv-1   |     del self.db
rest_variantvalidator-restvv-1   | AttributeError: db
rest_variantvalidator-restvv-1   | [2023-04-20 14:55:47 +0000] [7] [INFO] Shutting down: Master
rest_variantvalidator-restvv-1   | [2023-04-20 14:55:47 +0000] [7] [INFO] Reason: Worker failed to boot.

What would you suggest? I'll have a look at the manual install (outside docker), but I'm afraid this will be a pain in the ass.

@vidboda
Copy link
Author

vidboda commented Apr 20, 2023

looks like restvv does not wait for vdb to be up to launch? should it?

@Peter-J-Freeman
Copy link
Contributor

No. Interesting point thought. I'm going to see if I can tweak the start up order

@Peter-J-Freeman
Copy link
Contributor

Try replacing the content of docker-compose with

version: '3'

services:
  vdb:
    build:
      context: .
      dockerfile: vdb_docker.df
    ports:
      - "33061:3306"
    expose:
      - "33061"
  vvta:
    build:
      context: .
      dockerfile: vvta_docker.df
    depends_on:
      - vdb
    ports:
      - "54321:5432"
    expose:
      - "54321"
  seqrepo:
    build:
      context: .
      dockerfile: vvsr_docker.df
    depends_on:
      - vvta
    volumes:
      - seqdata:/usr/local/share/seqrepo
  restvv:
    build: .
    depends_on:
      - seqrepo
    volumes:
      - logs:/usr/local/share/logs
      - seqdata:/usr/local/share/seqrepo
      - share:/usr/local/share
    ports:
      - "5000:5000"
      - "8000:8000"
    expose:
      - "5000"
      - "8000"

volumes:
  share:
    driver: local
    driver_opts:
      type: 'none'
      o: 'bind'
      device: '${HOME}/variantvalidator_data/share'
  seqdata:
    driver: local
    driver_opts:
      type: 'none'
      o: 'bind'
      device: '${HOME}/variantvalidator_data/share/seqrepo'
  logs:
    driver: local
    driver_opts:
      type: 'none'
      o: 'bind'
      device: '${HOME}/variantvalidator_data/share/logs'

Once you complete the docker-compose build step

run

$ docker-compose up
# Shut down when database ready to accept commections with ctrl c
$ docker-compose up

@Peter-J-Freeman
Copy link
Contributor

Containers should now start in order from top to bottom with vvrest last

@vidboda
Copy link
Author

vidboda commented Apr 20, 2023

No - restvv is still starting before vdb is done:

below the 2nd docker-compose up

# docker-compose up
[+] Running 4/0
 ✔ Container rest_variantvalidator-vdb-1      Created                                                                                                                                                                                                       0.0s 
 ✔ Container rest_variantvalidator-vvta-1     Created                                                                                                                                                                                                       0.0s 
 ✔ Container rest_variantvalidator-seqrepo-1  Created                                                                                                                                                                                                       0.0s 
 ✔ Container rest_variantvalidator-restvv-1   Created                                                                                                                                                                                                       0.0s 
Attaching to rest_variantvalidator-restvv-1, rest_variantvalidator-seqrepo-1, rest_variantvalidator-vdb-1, rest_variantvalidator-vvta-1
rest_variantvalidator-vdb-1      | 2023-04-20 18:43:24+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 5.7.42-1debian10 started.
rest_variantvalidator-vvta-1     | 
rest_variantvalidator-vvta-1     | PostgreSQL Database directory appears to contain a database; Skipping initialization
rest_variantvalidator-vvta-1     | 
rest_variantvalidator-vvta-1     | 2023-04-20 18:43:25.404 UTC [1] LOG:  starting PostgreSQL 12.6 (Debian 12.6-1.pgdg100+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 8.3.0-6) 8.3.0, 64-bit
rest_variantvalidator-vvta-1     | 2023-04-20 18:43:25.405 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
rest_variantvalidator-vvta-1     | 2023-04-20 18:43:25.405 UTC [1] LOG:  listening on IPv6 address "::", port 5432
rest_variantvalidator-vvta-1     | 2023-04-20 18:43:25.436 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
rest_variantvalidator-vvta-1     | 2023-04-20 18:43:25.499 UTC [26] LOG:  database system was shut down at 2023-04-20 18:43:18 UTC
rest_variantvalidator-vvta-1     | 2023-04-20 18:43:25.523 UTC [1] LOG:  database system is ready to accept connections
rest_variantvalidator-seqrepo-1 exited with code 0
rest_variantvalidator-restvv-1   | [2023-04-20 18:43:26 +0000] [8] [INFO] Starting gunicorn 20.1.0
rest_variantvalidator-restvv-1   | [2023-04-20 18:43:26 +0000] [8] [INFO] Listening at: http://0.0.0.0:8000 (8)
rest_variantvalidator-restvv-1   | [2023-04-20 18:43:26 +0000] [8] [INFO] Using worker: gthread
rest_variantvalidator-restvv-1   | [2023-04-20 18:43:26 +0000] [9] [INFO] Booting worker with pid: 9
rest_variantvalidator-restvv-1   | Exception ignored in: <function Mixin.__del__ at 0x7fec1f91c0d0>
rest_variantvalidator-restvv-1   | Traceback (most recent call last):
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/VariantValidator/modules/vvMixinInit.py", line 213, in __del__
rest_variantvalidator-restvv-1   |     del self.db
rest_variantvalidator-restvv-1   | AttributeError: db
rest_variantvalidator-restvv-1   | [2023-04-20 18:43:27 +0000] [8] [INFO] Shutting down: Master
rest_variantvalidator-restvv-1   | [2023-04-20 18:43:27 +0000] [8] [INFO] Reason: Worker failed to boot.
rest_variantvalidator-restvv-1 exited with code 3
rest_variantvalidator-vdb-1      | 2023-04-20 18:44:07+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
rest_variantvalidator-vdb-1      | 2023-04-20 18:44:07+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 5.7.42-1debian10 started.
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:58.755053Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:58.757825Z 0 [Note] mysqld (mysqld 5.7.42) starting as process 1 ...
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:58.762119Z 0 [Note] InnoDB: PUNCH HOLE support available
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:58.762147Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:58.762150Z 0 [Note] InnoDB: Uses event mutexes
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:58.762152Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:58.762158Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.13
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:58.762160Z 0 [Note] InnoDB: Using Linux native AIO
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:58.762629Z 0 [Note] InnoDB: Number of pools: 1
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:58.762871Z 0 [Note] InnoDB: Using CPU crc32 instructions
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:58.767155Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:58.780358Z 0 [Note] InnoDB: Completed initialization of buffer pool
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:58.784799Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:58.800401Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:58.828648Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:58.828968Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:59.091886Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:59.092681Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:59.092730Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:59.098859Z 0 [Note] InnoDB: 5.7.42 started; log sequence number 2767445
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:59.099075Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:59.099511Z 0 [Note] Plugin 'FEDERATED' is disabled.
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:59.102211Z 0 [Note] InnoDB: Buffer pool(s) load completed at 230420 18:44:59
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:59.112135Z 0 [Note] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:59.112213Z 0 [Note] Skipping generation of SSL certificates as certificate files are present in data directory.
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:59.112227Z 0 [Warning] A deprecated TLS version TLSv1 is enabled. Please use TLSv1.2 or higher.
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:59.112230Z 0 [Warning] A deprecated TLS version TLSv1.1 is enabled. Please use TLSv1.2 or higher.
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:59.113099Z 0 [Warning] CA certificate ca.pem is self signed.
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:59.113328Z 0 [Note] Skipping generation of RSA key pair as key files are present in data directory.
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:59.114075Z 0 [Note] Server hostname (bind-address): '*'; port: 3306
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:59.115154Z 0 [Note] IPv6 is available.
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:59.115232Z 0 [Note]   - '::' resolves to '::';
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:59.115291Z 0 [Note] Server socket created on IP: '::'.
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:59.129001Z 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.
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:59.137175Z 0 [Note] Event Scheduler: Loaded 0 events
rest_variantvalidator-vdb-1      | 2023-04-20T18:44:59.137538Z 0 [Note] mysqld: ready for connections.
rest_variantvalidator-vdb-1      | Version: '5.7.42'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  MySQL Community Server (GPL)

There must be a trick - I'll search for it tomorrow morning.
thx

@Peter-J-Freeman
Copy link
Contributor

Did you try to do docker-compose run again. Wondered if the API is sparking up

@vidboda
Copy link
Author

vidboda commented Apr 21, 2023

yes, I tried several times - the startup sequence is identical

The vdb container takes a while (1-2 minutes) to show up as you can see on the log

@vidboda
Copy link
Author

vidboda commented Apr 21, 2023

Hi,

good and bad news:

I modified the docker-compose.yml file to take advantage of the healthcheck capability of docker.
the vdb part becomes:

  vdb:
    build:
      context: .
      dockerfile: vdb_docker.df
    ports:
      - "33061:3306"
    expose:
      - "33061"
    healthcheck:
      test: ["CMD", "mysqladmin" ,"ping", "-h", "localhost"]
      timeout: 20s
      retries: 10

and the vvta:

  vvta:
    build:
      context: .
      dockerfile: vvta_docker.df
    depends_on:
      vdb:
        condition: service_healthy

modifications on the healthcheck attribute (do we say that for yml?) for the 1st and depends_on for the 2nd.
So the start sequence works as expected:

rest_variantvalidator-vdb-1      | 2023-04-21 07:06:35+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 5.7.42-1debian10 started.
rest_variantvalidator-vdb-1      | 2023-04-21 07:07:16+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
rest_variantvalidator-vdb-1      | 2023-04-21 07:07:16+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 5.7.42-1debian10 started.
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.581113Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.584668Z 0 [Note] mysqld (mysqld 5.7.42) starting as process 1 ...
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.588851Z 0 [Note] InnoDB: PUNCH HOLE support available
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.588877Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.588880Z 0 [Note] InnoDB: Uses event mutexes
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.588883Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.588889Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.13
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.588892Z 0 [Note] InnoDB: Using Linux native AIO
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.589352Z 0 [Note] InnoDB: Number of pools: 1
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.589614Z 0 [Note] InnoDB: Using CPU crc32 instructions
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.593762Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.606758Z 0 [Note] InnoDB: Completed initialization of buffer pool
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.609666Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.625520Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.650522Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.650612Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.907199Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.907998Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.908046Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.910206Z 0 [Note] InnoDB: 5.7.42 started; log sequence number 2767557
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.910500Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.910779Z 0 [Note] Plugin 'FEDERATED' is disabled.
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.912344Z 0 [Note] InnoDB: Buffer pool(s) load completed at 230421  7:08:07
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.920543Z 0 [Note] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.920607Z 0 [Note] Skipping generation of SSL certificates as certificate files are present in data directory.
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.920623Z 0 [Warning] A deprecated TLS version TLSv1 is enabled. Please use TLSv1.2 or higher.
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.920634Z 0 [Warning] A deprecated TLS version TLSv1.1 is enabled. Please use TLSv1.2 or higher.
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.921353Z 0 [Warning] CA certificate ca.pem is self signed.
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.921443Z 0 [Note] Skipping generation of RSA key pair as key files are present in data directory.
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.922091Z 0 [Note] Server hostname (bind-address): '*'; port: 3306
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.922225Z 0 [Note] IPv6 is available.
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.922262Z 0 [Note]   - '::' resolves to '::';
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.922365Z 0 [Note] Server socket created on IP: '::'.
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.937054Z 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.
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.944844Z 0 [Note] Event Scheduler: Loaded 0 events
rest_variantvalidator-vdb-1      | 2023-04-21T07:08:07.946623Z 0 [Note] mysqld: ready for connections.
rest_variantvalidator-vdb-1      | Version: '5.7.42'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  MySQL Community Server (GPL)
rest_variantvalidator-vvta-1     | 
rest_variantvalidator-vvta-1     | PostgreSQL Database directory appears to contain a database; Skipping initialization
rest_variantvalidator-vvta-1     | 
rest_variantvalidator-vvta-1     | 2023-04-21 07:08:36.417 UTC [1] LOG:  starting PostgreSQL 12.6 (Debian 12.6-1.pgdg100+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 8.3.0-6) 8.3.0, 64-bit
rest_variantvalidator-vvta-1     | 2023-04-21 07:08:36.417 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
rest_variantvalidator-vvta-1     | 2023-04-21 07:08:36.417 UTC [1] LOG:  listening on IPv6 address "::", port 5432
rest_variantvalidator-vvta-1     | 2023-04-21 07:08:36.457 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
rest_variantvalidator-vvta-1     | 2023-04-21 07:08:36.519 UTC [26] LOG:  database system was shut down at 2023-04-21 07:06:29 UTC
rest_variantvalidator-vvta-1     | 2023-04-21 07:08:36.541 UTC [1] LOG:  database system is ready to accept connections
rest_variantvalidator-seqrepo-1 exited with code 0
rest_variantvalidator-restvv-1   | [2023-04-21 07:08:37 +0000] [7] [INFO] Starting gunicorn 20.1.0
rest_variantvalidator-restvv-1   | [2023-04-21 07:08:37 +0000] [7] [INFO] Listening at: http://0.0.0.0:8000 (7)
rest_variantvalidator-restvv-1   | [2023-04-21 07:08:37 +0000] [7] [INFO] Using worker: gthread
rest_variantvalidator-restvv-1   | [2023-04-21 07:08:37 +0000] [8] [INFO] Booting worker with pid: 8
rest_variantvalidator-restvv-1   | Exception ignored in: <function Mixin.__del__ at 0x7fb0a65c3d90>
rest_variantvalidator-restvv-1   | Traceback (most recent call last):
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/VariantValidator/modules/vvMixinInit.py", line 213, in __del__
rest_variantvalidator-restvv-1   |     del self.db
rest_variantvalidator-restvv-1   | AttributeError: db
rest_variantvalidator-restvv-1   | [2023-04-21 07:08:38 +0000] [7] [INFO] Shutting down: Master
rest_variantvalidator-restvv-1   | [2023-04-21 07:08:38 +0000] [7] [INFO] Reason: Worker failed to boot.
rest_variantvalidator-restvv-1 exited with code 3

but sadly for me, as you can see the restvv container still fails miserably. This time no clue.

@ifokkema
Copy link

rest_variantvalidator-restvv-1   | Exception ignored in: <function Mixin.__del__ at 0x7fb0a65c3d90>
rest_variantvalidator-restvv-1   | Traceback (most recent call last):
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/VariantValidator/modules/vvMixinInit.py", line 213, in __del__
rest_variantvalidator-restvv-1   |     del self.db
rest_variantvalidator-restvv-1   | AttributeError: db

This error only happens, as far as I know, when __del__ is run more than once. So while obviously, there is a bug somewhere that calls __del__ more than once, it also seems that simply catching or preventing that exception is easy to do, which might fix things as well.

@vidboda
Copy link
Author

vidboda commented Apr 21, 2023

Right, I'd need to fork variantValidator and point the Dockerfile to my repo.

However I'm not familiar with the egg part of the command

git+https://github.com/openvar/variantValidator@master#egg=VariantValidator

in the Dockerfile. Does it require a specific action on the repo, apart from modifying the code of the vvMixinInit.py module file?

I'll not be able to test until at least tuesday.

Thx for the tip.

@vidboda
Copy link
Author

vidboda commented Apr 28, 2023

Hey, I am having similar issues building on linux. I created another issue. I am getting the same AttributeError: 'UTA_postgresql' object has no attribute '_pool' error as earlier but the debian mysql update does not fix it.

It occurs for me on the docker compose up step.

weird this one is suppposed to be fixed.

@Peter-J-Freeman
Copy link
Contributor

Peter-J-Freeman commented Apr 28, 2023

@hotsoupisgood , think you have not set the path to your SeqRepo database correctly. See here #96 (comment)

@vidboda
Copy link
Author

vidboda commented Apr 28, 2023

Have you made sure all the host-machine directories are made?

yes those are made, and the seqrepo is there:

# ll ~/variantvalidator_data/share/seqrepo/
total 0
drwxr-xr-x. 3 restvv restvv 20 Apr 25 10:50 VV_SR_2022_11

# du -sh ~/variantvalidator_data/share/seqrepo/VV_SR_2022_11/
3.0G    /root/variantvalidator_data/share/seqrepo/VV_SR_2022_11/

@Peter-J-Freeman
Copy link
Contributor

Sorry, @beboche . Was getting confused between 2 issues. Back on this one

@Peter-J-Freeman
Copy link
Contributor

The issue that crops up every time on your error logs @beboche is this one

vvta_1 | PostgreSQL Database directory appears to contain a database; Skipping initialization

The section Skipping initialization might be a clue?

I am doing a full system prune of docker on my system and re-building using the .yml file in master and the build process in here. https://github.com/openvar/rest_variantValidator/blob/master/docs/DOCKER.md. Current master version. Will get back to you.

@Peter-J-Freeman
Copy link
Contributor

Also @beboche . Have you considered building locally. Since you update regularly it might be easier for you to maintain. Once built it is generally updating code and restarting or updating a database and re-starting. Happy to help you through the build.

@Peter-J-Freeman
Copy link
Contributor

I am doing a full system prune of docker on my system and re-building using the .yml file in master and the build process in here. https://github.com/openvar/rest_variantValidator/blob/master/docs/DOCKER.md. Current master version. Will get back to you.

Ok, that worked for me.

@beboche

what do you get if you run docker-compose up vvta

@vidboda
Copy link
Author

vidboda commented Apr 28, 2023

Also @beboche . Have you considered building locally. Since you update regularly it might be easier for you to maintain. Once built it is generally updating code and restarting or updating a database and re-starting. Happy to help you through the build.

maybe I should, indeed

what do you get if you run docker-compose up vvta

# docker-compose up vvta
[+] Running 2/0
 ✔ Container rest_variantvalidator-vdb-1   Created                                                                                                                                                       0.0s 
 ✔ Container rest_variantvalidator-vvta-1  Created                                                                                                                                                       0.0s 
Attaching to rest_variantvalidator-vvta-1
rest_variantvalidator-vvta-1  | 
rest_variantvalidator-vvta-1  | PostgreSQL Database directory appears to contain a database; Skipping initialization
rest_variantvalidator-vvta-1  | 
rest_variantvalidator-vvta-1  | 2023-04-28 09:13:11.081 UTC [1] LOG:  starting PostgreSQL 12.6 (Debian 12.6-1.pgdg100+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 8.3.0-6) 8.3.0, 64-bit
rest_variantvalidator-vvta-1  | 2023-04-28 09:13:11.082 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
rest_variantvalidator-vvta-1  | 2023-04-28 09:13:11.082 UTC [1] LOG:  listening on IPv6 address "::", port 5432
rest_variantvalidator-vvta-1  | 2023-04-28 09:13:11.107 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
rest_variantvalidator-vvta-1  | 2023-04-28 09:13:11.160 UTC [26] LOG:  database system was shut down at 2023-04-28 09:10:31 UTC
rest_variantvalidator-vvta-1  | 2023-04-28 09:13:11.178 UTC [1] LOG:  database system is ready to accept connections

@vidboda
Copy link
Author

vidboda commented Apr 28, 2023

The section Skipping initialization might be a clue?

you do not have that message?

@Peter-J-Freeman
Copy link
Contributor

The section Skipping initialization might be a clue?

you do not have that message?

Yes I did this time. So its not that. mine still starts. Just working through the log see if we can figure out exactly what fails.

try docker-compose up vdb. Make sure that says it is ready to accept connections.

I still think that you might be better setting up locally though. Save you headaches in the future. Are you on a linux server? The build isnt's particularly difficult.

If you can install conda, postgres mysql and sqlite. it doesn't take long and once installed it is very reliable

@vidboda
Copy link
Author

vidboda commented Apr 28, 2023

I still think that you might be better setting up locally though. Save you headaches in the future. Are you on a linux server? The build isnt's particularly difficult.

yes almalinux 9 - ok I'll consider that

@Peter-J-Freeman
Copy link
Contributor

Let me know if you want to set up a call to go through it

@vidboda
Copy link
Author

vidboda commented Apr 28, 2023

Let me know if you want to set up a call to go through it

I'll check the doc and let you know, thx

@vidboda
Copy link
Author

vidboda commented Apr 28, 2023

ran vdb again:

# docker-compose up vdb
[+] Running 1/0
 ✔ Container rest_variantvalidator-vdb-1  Created                                                                                                                                                        0.0s 
Attaching to rest_variantvalidator-vdb-1
rest_variantvalidator-vdb-1  | 2023-04-28 09:54:08+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 5.7.42-1debian10 started.
rest_variantvalidator-vdb-1  | 2023-04-28 09:55:16+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
rest_variantvalidator-vdb-1  | 2023-04-28 09:55:16+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 5.7.42-1debian10 started.
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:18.875443Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:18.881443Z 0 [Note] mysqld (mysqld 5.7.42) starting as process 1 ...
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:18.887904Z 0 [Note] InnoDB: PUNCH HOLE support available
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:18.887939Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:18.887943Z 0 [Note] InnoDB: Uses event mutexes
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:18.887945Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:18.887950Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.13
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:18.887953Z 0 [Note] InnoDB: Using Linux native AIO
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:18.888728Z 0 [Note] InnoDB: Number of pools: 1
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:18.889182Z 0 [Note] InnoDB: Using CPU crc32 instructions
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:18.894918Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:18.913084Z 0 [Note] InnoDB: Completed initialization of buffer pool
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:18.918571Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:18.936238Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:18.982738Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:18.982924Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:19.302616Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:19.303387Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:19.303411Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:19.305600Z 0 [Note] InnoDB: Waiting for purge to start
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:19.355930Z 0 [Note] InnoDB: 5.7.42 started; log sequence number 2767702
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:19.356566Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:19.357186Z 0 [Note] Plugin 'FEDERATED' is disabled.
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:19.358815Z 0 [Note] InnoDB: Buffer pool(s) load completed at 230428  9:56:19
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:19.368141Z 0 [Note] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:19.368266Z 0 [Note] Skipping generation of SSL certificates as certificate files are present in data directory.
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:19.368318Z 0 [Warning] A deprecated TLS version TLSv1 is enabled. Please use TLSv1.2 or higher.
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:19.368344Z 0 [Warning] A deprecated TLS version TLSv1.1 is enabled. Please use TLSv1.2 or higher.
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:19.369227Z 0 [Warning] CA certificate ca.pem is self signed.
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:19.369332Z 0 [Note] Skipping generation of RSA key pair as key files are present in data directory.
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:19.370185Z 0 [Note] Server hostname (bind-address): '*'; port: 3306
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:19.370548Z 0 [Note] IPv6 is available.
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:19.370620Z 0 [Note]   - '::' resolves to '::';
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:19.370662Z 0 [Note] Server socket created on IP: '::'.
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:19.395977Z 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.
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:19.405434Z 0 [Note] Event Scheduler: Loaded 0 events
rest_variantvalidator-vdb-1  | 2023-04-28T09:56:19.405920Z 0 [Note] mysqld: ready for connections.
rest_variantvalidator-vdb-1  | Version: '5.7.42'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  MySQL Community Server (GPL)

@Peter-J-Freeman
Copy link
Contributor

so the databases seem to run just fine. But when you hit docker-compose up, things start to exit?

@vidboda
Copy link
Author

vidboda commented Apr 28, 2023

well the databases start well but the vv worker fails to boot

@vidboda
Copy link
Author

vidboda commented Apr 28, 2023

check the last lines:

# docker-compose up
[+] Running 4/0
 ✔ Container rest_variantvalidator-vdb-1      Created                                                                                                                                                    0.0s 
 ✔ Container rest_variantvalidator-vvta-1     Created                                                                                                                                                    0.0s 
 ✔ Container rest_variantvalidator-seqrepo-1  Created                                                                                                                                                    0.0s 
 ✔ Container rest_variantvalidator-restvv-1   Created                                                                                                                                                    0.0s 
Attaching to rest_variantvalidator-restvv-1, rest_variantvalidator-seqrepo-1, rest_variantvalidator-vdb-1, rest_variantvalidator-vvta-1
rest_variantvalidator-vdb-1      | 2023-04-28 10:23:46+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 5.7.42-1debian10 started.
rest_variantvalidator-vdb-1      | 2023-04-28 10:24:47+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
rest_variantvalidator-vdb-1      | 2023-04-28 10:24:47+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 5.7.42-1debian10 started.
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:49.240181Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:49.244252Z 0 [Note] mysqld (mysqld 5.7.42) starting as process 1 ...
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:49.249220Z 0 [Note] InnoDB: PUNCH HOLE support available
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:49.249256Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:49.249259Z 0 [Note] InnoDB: Uses event mutexes
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:49.249261Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:49.249267Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.13
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:49.249269Z 0 [Note] InnoDB: Using Linux native AIO
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:49.253237Z 0 [Note] InnoDB: Number of pools: 1
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:49.253541Z 0 [Note] InnoDB: Using CPU crc32 instructions
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:49.258619Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:49.274594Z 0 [Note] InnoDB: Completed initialization of buffer pool
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:49.280771Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:49.298870Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:49.873541Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:49.873752Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:56.099936Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:56.100713Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:56.100731Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:56.104794Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 6824ms. The settings might not be optimal. (flushed=0 and evicted=0, during the time.)
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:56.104832Z 0 [Note] InnoDB: 5.7.42 started; log sequence number 2767730
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:56.106525Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:56.107053Z 0 [Note] Plugin 'FEDERATED' is disabled.
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:56.108760Z 0 [Note] InnoDB: Buffer pool(s) load completed at 230428 10:25:56
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:56.116290Z 0 [Note] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:56.116477Z 0 [Note] Skipping generation of SSL certificates as certificate files are present in data directory.
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:56.116512Z 0 [Warning] A deprecated TLS version TLSv1 is enabled. Please use TLSv1.2 or higher.
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:56.116523Z 0 [Warning] A deprecated TLS version TLSv1.1 is enabled. Please use TLSv1.2 or higher.
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:56.117343Z 0 [Warning] CA certificate ca.pem is self signed.
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:56.117515Z 0 [Note] Skipping generation of RSA key pair as key files are present in data directory.
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:56.118273Z 0 [Note] Server hostname (bind-address): '*'; port: 3306
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:56.118616Z 0 [Note] IPv6 is available.
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:56.118690Z 0 [Note]   - '::' resolves to '::';
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:56.118769Z 0 [Note] Server socket created on IP: '::'.
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:57.229234Z 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.
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:57.241101Z 0 [Note] Event Scheduler: Loaded 0 events
rest_variantvalidator-vdb-1      | 2023-04-28T10:25:57.241652Z 0 [Note] mysqld: ready for connections.
rest_variantvalidator-vdb-1      | Version: '5.7.42'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  MySQL Community Server (GPL)
rest_variantvalidator-vvta-1     | 
rest_variantvalidator-vvta-1     | PostgreSQL Database directory appears to contain a database; Skipping initialization
rest_variantvalidator-vvta-1     | 
rest_variantvalidator-vvta-1     | 2023-04-28 10:26:37.948 UTC [1] LOG:  starting PostgreSQL 12.6 (Debian 12.6-1.pgdg100+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 8.3.0-6) 8.3.0, 64-bit
rest_variantvalidator-vvta-1     | 2023-04-28 10:26:37.949 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
rest_variantvalidator-vvta-1     | 2023-04-28 10:26:37.949 UTC [1] LOG:  listening on IPv6 address "::", port 5432
rest_variantvalidator-vvta-1     | 2023-04-28 10:26:39.911 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
rest_variantvalidator-vvta-1     | 2023-04-28 10:26:43.905 UTC [26] LOG:  database system was shut down at 2023-04-28 09:26:15 UTC
rest_variantvalidator-vvta-1     | 2023-04-28 10:26:44.876 UTC [1] LOG:  database system is ready to accept connections
rest_variantvalidator-seqrepo-1 exited with code 0
rest_variantvalidator-restvv-1   | [2023-04-28 10:27:20 +0000] [7] [INFO] Starting gunicorn 20.1.0
rest_variantvalidator-restvv-1   | [2023-04-28 10:27:20 +0000] [7] [INFO] Listening at: http://0.0.0.0:8000 (7)
rest_variantvalidator-restvv-1   | [2023-04-28 10:27:20 +0000] [7] [INFO] Using worker: gthread
rest_variantvalidator-restvv-1   | [2023-04-28 10:27:20 +0000] [8] [INFO] Booting worker with pid: 8
rest_variantvalidator-restvv-1   | [2023-04-28 10:27:23 +0000] [7] [INFO] Shutting down: Master
rest_variantvalidator-restvv-1   | [2023-04-28 10:27:23 +0000] [7] [INFO] Reason: Worker failed to boot.
rest_variantvalidator-restvv-1 exited with code 3

@Peter-J-Freeman
Copy link
Contributor

OK, so I think it must be this

rest_variantvalidator-restvv-1 | [2023-04-28 10:27:20 +0000] [7] [INFO] Starting gunicorn 20.1.0
rest_variantvalidator-restvv-1 | [2023-04-28 10:27:20 +0000] [7] [INFO] Listening at: http://0.0.0.0:8000 (7)
rest_variantvalidator-restvv-1 | [2023-04-28 10:27:20 +0000] [7] [INFO] Using worker: gthread
rest_variantvalidator-restvv-1 | [2023-04-28 10:27:20 +0000] [8] [INFO] Booting worker with pid: 8
rest_variantvalidator-restvv-1 | [2023-04-28 10:27:23 +0000] [7] [INFO] Shutting down: Master
rest_variantvalidator-restvv-1 | [2023-04-28 10:27:23 +0000] [7] [INFO] Reason: Worker failed to boot.

It looks like all databases are fine but for some reason gunicorn is not happy. Seems to fail

@Peter-J-Freeman
Copy link
Contributor

Peter-J-Freeman commented Apr 28, 2023

I get the following and everything keeps running

rest_variantvalidator-vdb-1 | 2023-04-28T10:31:21.089887Z 0 [Note] InnoDB: Waiting for purge to start
rest_variantvalidator-restvv-1 | [2023-04-28 10:31:21 +0000] [7] [INFO] Starting gunicorn 20.1.0
rest_variantvalidator-restvv-1 | [2023-04-28 10:31:21 +0000] [7] [INFO] Listening at: http://0.0.0.0:8000 (7)
rest_variantvalidator-restvv-1 | [2023-04-28 10:31:21 +0000] [7] [INFO] Using worker: gthread
rest_variantvalidator-restvv-1 | [2023-04-28 10:31:21 +0000] [8] [INFO] Booting worker with pid: 8
rest_variantvalidator-vdb-1 | 2023-04-28T10:31:21.141504Z 0 [Note] InnoDB: 5.7.30 started; log sequence number 230373758
rest_variantvalidator-vdb-1 | 2023-04-28T10:31:21.141878Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
rest_variantvalidator-vdb-1 | 2023-04-28T10:31:21.142137Z 0 [Note] Plugin 'FEDERATED' is disabled.
rest_variantvalidator-vdb-1 | 2023-04-28T10:31:21.154220Z 0 [Note] InnoDB: Buffer pool(s) load completed at 230428 12:31:21
rest_variantvalidator-vdb-1 | 2023-04-28T10:31:21.156941Z 0 [Note] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.
rest_variantvalidator-vdb-1 | 2023-04-28T10:31:21.156977Z 0 [Note] Skipping generation of SSL certificates as certificate files are present in data directory.
rest_variantvalidator-vdb-1 | 2023-04-28T10:31:21.157851Z 0 [Warning] CA certificate ca.pem is self signed.
rest_variantvalidator-vdb-1 | 2023-04-28T10:31:21.158065Z 0 [Note] Skipping generation of RSA key pair as key files are present in data directory.
rest_variantvalidator-vdb-1 | 2023-04-28T10:31:21.158312Z 0 [Note] Server hostname (bind-address): '*'; port: 3306
rest_variantvalidator-vdb-1 | 2023-04-28T10:31:21.158405Z 0 [Note] IPv6 is available.
rest_variantvalidator-vdb-1 | 2023-04-28T10:31:21.158528Z 0 [Note] - '::' resolves to '::';
rest_variantvalidator-vdb-1 | 2023-04-28T10:31:21.158606Z 0 [Note] Server socket created on IP: '::'.
rest_variantvalidator-vdb-1 | 2023-04-28T10:31:21.159863Z 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.
rest_variantvalidator-vdb-1 | 2023-04-28T10:31:21.167119Z 0 [Note] Failed to start slave threads for channel ''
rest_variantvalidator-vdb-1 | 2023-04-28T10:31:21.172211Z 0 [Note] Event Scheduler: Loaded 0 events
rest_variantvalidator-vdb-1 | 2023-04-28T10:31:21.172528Z 0 [Note] mysqld: ready for connections.
rest_variantvalidator-vdb-1 | Version: '5.7.30-0ubuntu0.18.04.1' socket: '/var/run/mysqld/mysqld.sock' port: 3306 (Ubuntu)

@vidboda
Copy link
Author

vidboda commented Apr 28, 2023

I think I have a clue

I don't

I'll try to run gunicorn in preload moed, to get more detailed error message.

@Peter-J-Freeman
Copy link
Contributor

Nice. At least we now have a clue.

@vidboda
Copy link
Author

vidboda commented May 2, 2023

Hi - I ran gunicorn in preload mode, this gave me the following python error:

Note the line _mysql_connector.MySQLInterfaceError: Host '172.19.0.5' is not allowed to connect to this MySQL server

I suppose 172.19.0.5 is the vv docker address? So it's not allowed but not sure why. I cut the log but the mysql vdb started fine rest_variantvalidator-vdb-1 | 2023-05-02T09:25:59.622229Z 0 [Note] mysqld: ready for connections.

rest_variantvalidator-seqrepo-1 exited with code 0
rest_variantvalidator-restvv-1   | Traceback (most recent call last):
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/mysql/connector/connection_cext.py", line 291, in _open_connection
rest_variantvalidator-restvv-1   |     self._cmysql.connect(**cnx_kwargs)
rest_variantvalidator-restvv-1   | _mysql_connector.MySQLInterfaceError: Host '172.19.0.5' is not allowed to connect to this MySQL server
rest_variantvalidator-restvv-1   | 
rest_variantvalidator-restvv-1   | The above exception was the direct cause of the following exception:
rest_variantvalidator-restvv-1   | 
rest_variantvalidator-restvv-1   | Traceback (most recent call last):
rest_variantvalidator-restvv-1   |   File "/usr/local/bin/gunicorn", line 8, in <module>
rest_variantvalidator-restvv-1   |     sys.exit(run())
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/gunicorn/app/wsgiapp.py", line 67, in run
rest_variantvalidator-restvv-1   |     WSGIApplication("%(prog)s [OPTIONS] [APP_MODULE]").run()
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/gunicorn/app/base.py", line 231, in run
rest_variantvalidator-restvv-1   |     super().run()
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/gunicorn/app/base.py", line 72, in run
rest_variantvalidator-restvv-1   |     Arbiter(self).run()
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/gunicorn/arbiter.py", line 58, in __init__
rest_variantvalidator-restvv-1   |     self.setup(app)
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/gunicorn/arbiter.py", line 118, in setup
rest_variantvalidator-restvv-1   |     self.app.wsgi()
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/gunicorn/app/base.py", line 67, in wsgi
rest_variantvalidator-restvv-1   |     self.callable = self.load()
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/gunicorn/app/wsgiapp.py", line 58, in load
rest_variantvalidator-restvv-1   |     return self.load_wsgiapp()
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/gunicorn/app/wsgiapp.py", line 48, in load_wsgiapp
rest_variantvalidator-restvv-1   |     return util.import_app(self.app_uri)
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/gunicorn/util.py", line 359, in import_app
rest_variantvalidator-restvv-1   |     mod = importlib.import_module(module)
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/importlib/__init__.py", line 126, in import_module
rest_variantvalidator-restvv-1   |     return _bootstrap._gcd_import(name[level:], package, level)
rest_variantvalidator-restvv-1   |   File "<frozen importlib._bootstrap>", line 1050, in _gcd_import
rest_variantvalidator-restvv-1   |   File "<frozen importlib._bootstrap>", line 1027, in _find_and_load
rest_variantvalidator-restvv-1   |   File "<frozen importlib._bootstrap>", line 1006, in _find_and_load_unlocked
rest_variantvalidator-restvv-1   |   File "<frozen importlib._bootstrap>", line 688, in _load_unlocked
rest_variantvalidator-restvv-1   |   File "<frozen importlib._bootstrap_external>", line 883, in exec_module
rest_variantvalidator-restvv-1   |   File "<frozen importlib._bootstrap>", line 241, in _call_with_frames_removed
rest_variantvalidator-restvv-1   |   File "/app/rest_VariantValidator/app.py", line 7, in <module>
rest_variantvalidator-restvv-1   |     from rest_VariantValidator.endpoints import api, representations, exceptions, request_parser
rest_variantvalidator-restvv-1   |   File "/app/rest_VariantValidator/endpoints/__init__.py", line 6, in <module>
rest_variantvalidator-restvv-1   |     from .variantvalidator_endpoints import api as ns_vv
rest_variantvalidator-restvv-1   |   File "/app/rest_VariantValidator/endpoints/variantvalidator_endpoints.py", line 9, in <module>
rest_variantvalidator-restvv-1   |     vval = VariantValidator.Validator()
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/VariantValidator/modules/vvMixinInit.py", line 100, in __init__
rest_variantvalidator-restvv-1   |     self.db = Database(self.dbConfig)
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/VariantValidator/modules/vvDBInit.py", line 16, in __init__
rest_variantvalidator-restvv-1   |     self.init_db()
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/VariantValidator/modules/vvDBInit.py", line 24, in init_db
rest_variantvalidator-restvv-1   |     self.pool = mysql.connector.pooling.MySQLConnectionPool(pool_size=5, **self.dbConfig)
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/mysql/connector/pooling.py", line 430, in __init__
rest_variantvalidator-restvv-1   |     self.add_connection()
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/mysql/connector/pooling.py", line 538, in add_connection
rest_variantvalidator-restvv-1   |     cnx = connect(**self._cnx_config)  # type: ignore[assignment]
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/mysql/connector/pooling.py", line 293, in connect
rest_variantvalidator-restvv-1   |     return CMySQLConnection(*args, **kwargs)
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/mysql/connector/connection_cext.py", line 120, in __init__
rest_variantvalidator-restvv-1   |     self.connect(**kwargs)
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/mysql/connector/abstracts.py", line 1181, in connect
rest_variantvalidator-restvv-1   |     self._open_connection()
rest_variantvalidator-restvv-1   |   File "/usr/local/lib/python3.10/site-packages/mysql/connector/connection_cext.py", line 296, in _open_connection
rest_variantvalidator-restvv-1   |     raise get_mysql_exception(
rest_variantvalidator-restvv-1   | mysql.connector.errors.DatabaseError: 1130 (HY000): Host '172.19.0.5' is not allowed to connect to this MySQL server
rest_variantvalidator-restvv-1 exited with code 1

@Peter-J-Freeman
Copy link
Contributor

This may be the difference. I'm building on a mac M1 With ARM using the container from here

For Arm chips e.g. Apple M1

FROM biarms/mysql:5.7

For other processors you need to select this.

For Intel chips

FROM mysql:5.7-debian

I was asked to change this to 5.7-debian bit I'm not sure if this is correct

The documentation seem to say 5.7 should work.

Try replacing the 5.7-debian with just 5.7

@vidboda
Copy link
Author

vidboda commented May 2, 2023

mysql:5.7 is an oracle linux, the package manager is yum and not aptitude - then the vdb_docker.df won't work.

I'll run some tests we should be able to fix this.

@vidboda
Copy link
Author

vidboda commented May 2, 2023

if I let docker-compose up vdb running, I have the following error - I believe the container is not well created:

# docker-compose up vdb
[+] Running 2/2
 ✔ Network rest_variantvalidator_default  Created                                                                                                                                                                                                                                            0.3s 
 ✔ Container rest_variantvalidator-vdb-1  Created                                                                                                                                                                                                                                            0.2s 
Attaching to rest_variantvalidator-vdb-1
rest_variantvalidator-vdb-1  | 2023-05-02 12:32:20+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 5.7.42-1debian10 started.
rest_variantvalidator-vdb-1  | 2023-05-02 12:33:26+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
rest_variantvalidator-vdb-1  | 2023-05-02 12:33:26+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 5.7.42-1debian10 started.
rest_variantvalidator-vdb-1  | 2023-05-02 12:34:25+00:00 [Note] [Entrypoint]: Initializing database files
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:32.485748Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:35.255730Z 0 [Warning] InnoDB: New log files created, LSN=45790
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:35.653866Z 0 [Warning] InnoDB: Creating foreign key constraint system tables.
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:35.770083Z 0 [Warning] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: b277c027-e8e5-11ed-838f-0242ac160002.
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:35.785162Z 0 [Warning] Gtid table is not ready to be used. Table 'mysql.gtid_executed' cannot be opened.
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:35.978089Z 0 [Warning] A deprecated TLS version TLSv1 is enabled. Please use TLSv1.2 or higher.
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:35.978160Z 0 [Warning] A deprecated TLS version TLSv1.1 is enabled. Please use TLSv1.2 or higher.
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:35.978769Z 0 [Warning] CA certificate ca.pem is self signed.
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:36.025713Z 1 [Warning] root@localhost is created with an empty password ! Please consider switching off the --initialize-insecure option.
rest_variantvalidator-vdb-1  | 2023-05-02 12:34:44+00:00 [Note] [Entrypoint]: Database files initialized
rest_variantvalidator-vdb-1  | 2023-05-02 12:34:44+00:00 [Note] [Entrypoint]: Starting temporary server
rest_variantvalidator-vdb-1  | 2023-05-02 12:34:44+00:00 [Note] [Entrypoint]: Waiting for server startup
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:51.879780Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:51.883843Z 0 [Note] mysqld (mysqld 5.7.42) starting as process 150 ...
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:51.888944Z 0 [Note] InnoDB: PUNCH HOLE support available
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:51.888973Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:51.888977Z 0 [Note] InnoDB: Uses event mutexes
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:51.888979Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:51.888982Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.13
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:51.888984Z 0 [Note] InnoDB: Using Linux native AIO
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:51.889468Z 0 [Note] InnoDB: Number of pools: 1
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:51.889693Z 0 [Note] InnoDB: Using CPU crc32 instructions
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:51.894381Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:51.910904Z 0 [Note] InnoDB: Completed initialization of buffer pool
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:51.915842Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:51.932614Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:51.967355Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:51.967687Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:52.231265Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:52.232277Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:52.232425Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:52.234966Z 0 [Note] InnoDB: Waiting for purge to start
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:52.285252Z 0 [Note] InnoDB: 5.7.42 started; log sequence number 2767392
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:52.285635Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:52.286025Z 0 [Note] Plugin 'FEDERATED' is disabled.
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:52.289135Z 0 [Note] InnoDB: Buffer pool(s) load completed at 230502 12:34:52
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:52.297670Z 0 [Note] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:52.297737Z 0 [Note] Skipping generation of SSL certificates as certificate files are present in data directory.
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:52.297754Z 0 [Warning] A deprecated TLS version TLSv1 is enabled. Please use TLSv1.2 or higher.
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:52.297765Z 0 [Warning] A deprecated TLS version TLSv1.1 is enabled. Please use TLSv1.2 or higher.
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:52.298443Z 0 [Warning] CA certificate ca.pem is self signed.
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:52.298510Z 0 [Note] Skipping generation of RSA key pair as key files are present in data directory.
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:52.313503Z 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.
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:52.322035Z 0 [Note] Event Scheduler: Loaded 0 events
rest_variantvalidator-vdb-1  | 2023-05-02T12:34:52.322433Z 0 [Note] mysqld: ready for connections.
rest_variantvalidator-vdb-1  | Version: '5.7.42'  socket: '/var/run/mysqld/mysqld.sock'  port: 0  MySQL Community Server (GPL)
rest_variantvalidator-vdb-1  | 2023-05-02 12:34:53+00:00 [Note] [Entrypoint]: Temporary server started.
rest_variantvalidator-vdb-1  | ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111)
rest_variantvalidator-vdb-1  | /usr/local/bin/docker-entrypoint.sh: line 282:   150 Killed                  "$@" --skip-networking --default-time-zone=SYSTEM --socket="${SOCKET}"
rest_variantvalidator-vdb-1 exited with code 1

we may be getting closer

@vidboda
Copy link
Author

vidboda commented May 2, 2023

It may be related to mysql 5.7 with some architectures and memory consumption - I'm experiencing the 16Go consumption described here:

docker-library/mysql#579

I'm trying mysql 8

@vidboda
Copy link
Author

vidboda commented May 2, 2023

Finally the docker resttvv api is running.

I just had to change the mysql version in the vdb_docker.df file. Working version for my config (AlmaLinux 9 on intel chips) is:

# For Intel chips
FROM mysql:8.0-debian

at the beginning of the df file.

I also had to change the Dockerfile very last line from:

CMD gunicorn -b 127.0.0.1:8000 app --threads=5 --chdir ./rest_VariantValidator/

to

CMD gunicorn -b 0.0.0.0:8000 app --threads=5 --chdir ./rest_VariantValidator/

to be able to reach VV API from another machine.

@Peter-J-Freeman
Copy link
Contributor

Good work. I am making edits. Shall I pull these into the repo?

@vidboda
Copy link
Author

vidboda commented May 3, 2023

Shall I pull these into the repo?

I think so

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

4 participants