Server not completing startup on install

Still testing setup on k8s clusters, and have had to install and uninstall a few times. Unfortunately, this all seems very unstable.

I have had some issues with the mysql database not completing every time.

At the moment, it has completed, but I am seeing that the servercomponent is not completing,

I can see a lot of the following in the db (mysql) log:

Access denied for user 'root'@'localhost' (using password: YES)

I am guessing this is the server database-waiter container that is failing to connect and check for the db being available.

Anyone else seen this and solved it?

FYI - This is both on k3s and on rke k8s clusters.

Once the DB migrations have run, the service-waiter should not cause access denied issues.

Does the service-waiter ever finish, i.e. does the server ever actually start?

The server never starts in this current setup.

I see a lot of errors like below in the database-waiter initContainer:

{"error":"Error 1130: Host '10.42.1.34' is not allowed to connect to this MySQL server","message":"retry","serviceContext":{"service":"service-waiter","version":""},"severity":"debug","time":"2020-07-14T18:25:19Z"}

and in the mysql logs:

2020-07-14T18:27:00.153003Z 17857 [Note] Access denied for user 'root'@'localhost' (using password: YES)

Right now I am seeing the same thing on both my clusters (k3s and rke) being managed with Rancher.

FYI - I managed to get an instance to start up completely yesterday - and I think I have everything set up as it should now. I will post a separate topic for this…

That’s great, @thomashansen!

Do you have a finding to share that solves the issue?

Afraid not - I rebuilt my cluster and did the install again, and this time it came up.

The only thing I know of right now that I have to do if I uninstall and re-install is to remove the labels that are added to the nodes during the install. Otherwise the node-daemon does not complete setup.

OK, thanks for the Info.

I am keen to find out though :wink: As I have done many install / uninstalls during testing…

So - had to re-install to reduce the length of the FQDN - and now I am seeing the problems again with the server not completing the install.

I can see that the db-migration service is having issues:

yarn run v1.13.0
$ node ./lib/wait-for-db.js
Using DB: db:3306/gitpod
Connection attempt 0/30 failed. Retrying in 5 seconds.
Connection attempt 1/30 failed. Retrying in 5 seconds.
Connection attempt 2/30 failed. Retrying in 5 seconds.
Connection attempt 3/30 failed. Retrying in 5 seconds.
Connection attempt 4/30 failed. Retrying in 5 seconds.
Connection attempt 5/30 failed. Retrying in 5 seconds.
Connection attempt 6/30 failed. Retrying in 5 seconds.
Connection attempt 7/30 failed. Retrying in 5 seconds.
Connection attempt 8/30 failed. Retrying in 5 seconds.
Connection attempt 9/30 failed. Retrying in 5 seconds.
Connection attempt 10/30 failed. Retrying in 5 seconds.
Connection attempt 11/30 failed. Retrying in 5 seconds.
Connection attempt 12/30 failed. Retrying in 5 seconds.
Connection attempt 13/30 failed. Retrying in 5 seconds.
Connection attempt 14/30 failed. Retrying in 5 seconds.
Connection attempt 15/30 failed. Retrying in 5 seconds.
Connection attempt 16/30 failed. Retrying in 5 seconds.
Connection attempt 17/30 failed. Retrying in 5 seconds.
Connection attempt 18/30 failed. Retrying in 5 seconds.
Connection attempt 19/30 failed. Retrying in 5 seconds.
Connection attempt 20/30 failed. Retrying in 5 seconds.
Connection attempt 21/30 failed. Retrying in 5 seconds.

… which would be the reason why the server and ws-managerbridge are not completing.

I cleaned up the labels on the nodes and also deleted the /var/gitpod/theia and /var/gitpod/docker directories on the nodes before re-installing.

Does this ring any bells or tell you where to look?

In case it is of any help, here are the logs I can see for the mysql instance:

2020-07-16 15:06:33+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 5.7.28-1debian9 started. 
2020-07-16 15:06:33+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql' 
2020-07-16 15:06:33+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 5.7.28-1debian9 started. 
2020-07-16T15:06:34.264273Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details). 
2020-07-16T15:06:34.266344Z 0 [Note] mysqld (mysqld 5.7.28) starting as process 1 ... 
2020-07-16T15:06:34.273136Z 0 [Note] InnoDB: PUNCH HOLE support available 
2020-07-16T15:06:34.273190Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 
2020-07-16T15:06:34.273197Z 0 [Note] InnoDB: Uses event mutexes 
2020-07-16T15:06:34.273202Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier 
2020-07-16T15:06:34.273211Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.11 
2020-07-16T15:06:34.273222Z 0 [Note] InnoDB: Using Linux native AIO 
2020-07-16T15:06:34.273553Z 0 [Note] InnoDB: Number of pools: 1 
2020-07-16T15:06:34.273680Z 0 [Note] InnoDB: Using CPU crc32 instructions 
2020-07-16T15:06:34.276016Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M 
2020-07-16T15:06:34.287897Z 0 [Note] InnoDB: Completed initialization of buffer pool 
2020-07-16T15:06:34.291006Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority(). 
2020-07-16T15:06:34.303115Z 0 [Note] InnoDB: Highest supported file format is Barracuda. 
2020-07-16T15:06:34.305670Z 0 [Note] InnoDB: Log scan progressed past the checkpoint lsn 2629376 
2020-07-16T15:06:34.574783Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 7872000 
2020-07-16T15:06:34.720424Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 10179427 
2020-07-16T15:06:34.721227Z 0 [Note] InnoDB: Database was not shutdown normally! 
2020-07-16T15:06:34.721254Z 0 [Note] InnoDB: Starting crash recovery. 
2020-07-16T15:06:34.845548Z 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 105741 row operations to undo 
2020-07-16T15:06:34.845593Z 0 [Note] InnoDB: Trx id counter is 1792 
2020-07-16T15:06:34.846159Z 0 [Note] InnoDB: Starting an apply batch of log records to the database... 
InnoDB: Progress in percent: 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 
2020-07-16T15:06:35.366856Z 0 [Note] InnoDB: Apply batch completed 
2020-07-16T15:06:35.471919Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1" 
2020-07-16T15:06:35.472002Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables 
2020-07-16T15:06:35.472167Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ... 
2020-07-16T15:06:35.472510Z 0 [Note] InnoDB: Starting in background the rollback of uncommitted transactions 
2020-07-16T15:06:35.472575Z 0 [Note] InnoDB: Rolling back trx with id 1291, 105741 rows to undo 
 
InnoDB: Progress in percents: 1 2 3 4 5 6 7 8 92020-07-16T15:06:36.072248Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB. 
2020-07-16T15:06:36.074288Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active. 
2020-07-16T15:06:36.074356Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active. 
2020-07-16T15:06:36.076989Z 0 [Note] InnoDB: 5.7.28 started; log sequence number 10179427 
2020-07-16T15:06:36.085201Z 0 [Note] Plugin 'FEDERATED' is disabled. 
2020-07-16T15:06:36.085213Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool 
2020-07-16T15:06:36.087303Z 0 [Note] InnoDB: Buffer pool(s) load completed at 200716 15:06:36 
2020-07-16T15:06:36.103333Z 0 [Note] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them. 
2020-07-16T15:06:36.103371Z 0 [Note] Skipping generation of SSL certificates as certificate files are present in data directory. 
2020-07-16T15:06:36.104132Z 0 [Warning] CA certificate ca.pem is self signed. 
2020-07-16T15:06:36.104181Z 0 [Note] Skipping generation of RSA key pair as key files are present in data directory. 
2020-07-16T15:06:36.104783Z 0 [Note] Server hostname (bind-address): '*'; port: 3306 
2020-07-16T15:06:36.104848Z 0 [Note] IPv6 is available. 
2020-07-16T15:06:36.104863Z 0 [Note]   - '::' resolves to '::'; 
2020-07-16T15:06:36.104893Z 0 [Note] Server socket created on IP: '::'. 
 10 11 12 13 14 15 16 17 18 19 20 21 22 23 242020-07-16T15:06:36.329023Z 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. 
 25 262020-07-16T15:06:36.344796Z 0 [Note] Event Scheduler: Loaded 0 events 
2020-07-16T15:06:36.345431Z 0 [Note] mysqld: ready for connections. 
Version: '5.7.28'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  MySQL Community Server (GPL) 
 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 1002020-07-16T15:06:36.932553Z 0 [Note] InnoDB: Rollback of trx with id 1291 completed 
2020-07-16T15:06:36.932677Z 0 [Note] InnoDB: Rollback of non-prepared transactions completed 
2020-07-16T15:06:43.526200Z 2 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:06:53.523662Z 24 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:07:03.513535Z 47 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:07:12.939221Z 68 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:07:13.510099Z 71 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:07:22.946563Z 91 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:07:23.511372Z 95 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:07:32.944824Z 116 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:07:33.553801Z 119 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:07:42.930937Z 140 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:07:43.498663Z 143 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:07:52.929729Z 164 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:07:53.519982Z 167 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:08:02.954631Z 188 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:08:03.509913Z 191 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:08:12.933678Z 212 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:08:13.499026Z 213 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:08:22.930675Z 236 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:08:23.505909Z 237 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:08:32.929448Z 260 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:08:33.581274Z 261 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:08:42.978659Z 284 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:08:43.508537Z 285 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:08:52.937149Z 308 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:08:53.517367Z 309 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:09:02.938049Z 330 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:09:03.517329Z 332 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:09:12.932402Z 354 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:09:13.493279Z 356 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:09:22.918509Z 378 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:09:23.507509Z 380 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:09:32.939079Z 401 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:09:33.517217Z 403 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:09:42.934871Z 423 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:09:43.509933Z 425 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:09:52.944221Z 445 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:09:53.507497Z 447 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:10:02.988202Z 467 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:10:03.561935Z 468 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:10:12.964261Z 489 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:10:13.496986Z 490 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:10:22.941522Z 510 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:10:23.502706Z 512 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:10:32.949343Z 532 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:10:33.532389Z 534 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:10:42.940012Z 551 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:10:43.504883Z 552 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:10:52.938579Z 572 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:10:53.510845Z 574 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:11:02.956981Z 594 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:11:03.544488Z 596 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:11:12.974426Z 616 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:11:13.514096Z 618 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:11:22.945418Z 637 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:11:23.518383Z 640 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:11:32.952481Z 659 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:11:33.534829Z 662 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:11:42.992780Z 681 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:11:43.506696Z 684 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:11:52.926674Z 703 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:11:53.498566Z 705 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:12:02.951873Z 725 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:12:03.518380Z 727 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:12:12.954911Z 747 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:12:13.527931Z 749 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:12:22.916127Z 769 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:12:23.490104Z 771 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:12:32.938356Z 790 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:12:33.545616Z 793 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:12:42.963855Z 812 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:12:43.565238Z 815 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:12:52.948827Z 834 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:12:53.499624Z 837 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:13:02.949739Z 856 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:13:03.508453Z 859 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:13:12.982786Z 878 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:13:13.526302Z 881 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:13:22.935388Z 900 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:13:23.501049Z 903 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:13:32.939076Z 922 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:13:33.535036Z 925 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:13:42.991236Z 944 [Note] Access denied for user 'root'@'localhost' (using password: YES) 
2020-07-16T15:13:43.533299Z 946 [Note] Access denied for user 'root'@'localhost' (using password: YES)