GoCD 20.7 crash after restart

[Luca G. Soave]

We have two GoCD 20.7 servers with business continuity and Postgres 9.6.10 backend.

Lately we re-started the standby and the master DB/GoCD but soon after, the standby crashed with the following error:

INFO   | jvm 1    | 2020/09/22 12:24:40 | Unable to create database upgrade script for database. The problem was: liquibase.exception.DatabaseException: Error executing SQL UPDATE public.databasechangeloglock SET LOCKED = TRUE, LOCKEDBY = 'go02-000-021-0', LOCKGRANTED = '2020-09-22 12:24:40.632' WHERE ID = 1 AND LOCKED = FALSE: ERROR: cannot execute UPDATE in a read-only transaction. The cause was: Error executing SQL UPDATE public.databasechangeloglock SET LOCKED = TRUE, LOCKEDBY = 'go02-000-021-0', LOCKGRANTED = '2020-09-22 12:24:40.632' WHERE ID = 1 AND LOCKED = FALSE: ERROR: cannot execute UPDATE in a read-only transaction

INFO   | jvm 1    | 2020/09/22 12:24:40 | liquibase.exception.LockException: liquibase.exception.DatabaseException: Error executing SQL UPDATE public.databasechangeloglock SET LOCKED = TRUE, LOCKEDBY = 'go02-000-021-0', LOCKGRANTED = '2020-09-22 12:24:40.632' WHERE ID = 1 AND LOCKED = FALSE: ERROR: cannot execute UPDATE in a read-only transaction

The master is up & running and the admin dashboard is working.

Do you have any help ?

Thanks in advance

Luca

[Luca G. Soave]

I tried to fix liquibase exception error by doing the following:

1. stopping gocd on both nodes
   
2. stopping the standby DB
3. on the primary clearing the lock by running  UPDATE DATABASECHANGELOGLOCK SET LOCKED=FALSE, LOCKGRANTED=null, LOCKEDBY=null;
   
4. stop the primary DB too
   
5. start the DB on secondary
6. start the db on primary
   
7. start gocd on secondary
   
8. start gocd on primary
   

after a while,  the secondary GoCD crashed again wit the following errors:

on go-server-wrapper.log:

INFO   | jvm 1    | 2020/07/09 14:35:40 | WARNING: An illegal reflective access operation has occurred
INFO   | jvm 1    | 2020/07/09 14:35:40 | WARNING: Illegal reflective access by org.bouncycastle.jcajce.provider.drbg.DRBG (onejar:lib/bcprov-jdk15on-1.59.jar) to constructor sun.security.provider.Sun()
INFO   | jvm 1    | 2020/07/09 14:35:40 | WARNING: Please consider reporting this to the maintainers of org.bouncycastle.jcajce.provider.drbg.DRBG
INFO   | jvm 1    | 2020/07/09 14:35:40 | WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
INFO   | jvm 1    | 2020/07/09 14:35:40 | WARNING: All illegal access operations will be denied in a future release
INFO   | jvm 1    | 2020/07/09 14:35:49 | ERROR: Failed to start GoCD server. Please check the logs.
INFO   | jvm 1    | 2020/07/09 14:35:49 | java.lang.RuntimeException: Failed to start GoCD server.
...

...

INFO   | jvm 1    | 2020/07/09 14:35:49 | Caused by: org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'webhookControllerV1' defined in URL [jar:file:/var/lib/go-server/work/jetty-192.168.0.48-8153-cruise.war-_go-any-/webapp/WEB-INF/lib/api-webhook-v1-20.1.0-11114.jar!/com/thoughtworks/go/apiv1/webhook/WebhookControllerV1.class]: Unsatisfied dependency expressed through constructor parameter 0; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'sqlSessionFactoryBean' defined in file [/var/lib/go-server/work/jetty-192.168.0.48-8153-cruise.war-_go-any-/webapp/WEB-INF/classes/com/thoughtworks/go/server/database/SqlSessionFactoryBean.class]: Unsatisfied dependency expressed through constructor parameter 0; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'databaseStrategy' defined in file [/var/lib/go-server/work/jetty-192.168.0.48-8153-cruise.war-_go-any-/webapp/WEB-INF/classes/com/thoughtworks/go/server/database/DatabaseStrategy.class]: Bean instantiation via constructor failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [com.thoughtworks.go.server.database.DatabaseStrategy]: Constructor threw exception; nested exception is java.lang.RuntimeException: Failed loading database provider [com.thoughtworks.go.postgresql.PostgresqlDatabasei]

than again on go-server.log

2020-09-25 10:02:13,350 ERROR [WrapperJarAppMain] DatabaseMigrator:65 - Unable to create database upgrade script for database. The problem was: liquibase.exception.DatabaseException: Error executing SQL UPDATE public.databasechangeloglock SET LOCKED = TRUE, LOCKEDBY = 'go02-000-021-0', LOCKGRANTED = '2020-09-25 10:02:13.346' WHERE ID = 1 AND LOCKED = FALSE: ERROR: cannot execute UPDATE in a read-only transaction. The cause was: Error executing SQL UPDATE public.databasechangeloglock SET LOCKED = TRUE, LOCKEDBY = 'go02-000-021-0', LOCKGRANTED = '2020-09-25 10:02:13.346' WHERE ID = 1 AND LOCKED = FALSE: ERROR: cannot execute UPDATE in a read-only transaction
liquibase.exception.LockException: liquibase.exception.DatabaseException: Error executing SQL UPDATE public.databasechangeloglock SET LOCKED = TRUE, LOCKEDBY = 'go02-000-021-0', LOCKGRANTED = '2020-09-25 10:02:13.346' WHERE ID = 1 AND LOCKED = FALSE: ERROR: cannot execute UPDATE in a read-only transaction

The primary is running fine, the dashboard is working and all the pipeline are in place.

Does anybody have any idea ?

Thanks in advance

[mahesh....@gmail.com]

Hello,

Can you try to restore the secondary db using the latest primary backup and see if that fixes the issue.

[Luca G. Soave]

We tried to restore the secondary db using the latest primary backup but didn't works, we still get the secondary gocd server crashing after trying to update the secondary DB which is in read-only.

Because we were coming from 20.4 where we had business continuity jar extension, we were used to see both primary and secondary GoCD servers up when the service was on primary.

Does that apply to 20.7 too, were business continuity is no more an extension but has been incorporated in GoCD server itself? Or with 20.7 we should expect to see the primary GoCD up and the secondary stopped (while both of DB can stay up anyway)?

Documentation didn't help here.

Failing over manually we can get the server up on secondary and the DB is fine but the dashboard is not able to authenticate and we are not sure why.

Could you please help?

Thanks in advance

Luca

[mahesh....@gmail.com]

Hello Luca,

I was able to reproduce this issue. Can you please create an issue on GitHub[1] with the relevant details.

[1] https://github.com/gocd/gocd/issues/new

Mahesh