Intermittent Null Pointer Exceptions when Schedule runs

351 views
Skip to first unread message

Brent Vaughn

unread,
Feb 13, 2023, 4:03:35 PM2/13/23
to rundeck-discuss

Over the weekend, I installed a completely new instance of Rundeck 4.9.0 based on Docker and a Postgres database based on Docker in the same docker-stack.yml file.

I sometimes get a Null Pointer Exception when a job tries to run. We have around 100 jobs and only 15 of them fail intermittently and it only happens on 30% of executions of those 15 jobs. Here is the stacktrack:  

[2023-02-11T17:05:02,268] ERROR services.ExecutionService - Failed while starting execution: 2779
java.lang.NullPointerException: null
at org.grails.orm.hibernate.GrailsHibernateTemplate.doExecute(GrailsHibernateTemplate.java:301) ~[grails-datastore-gorm-hibernate5-7.2.2.jar!/:?]
at org.grails.orm.hibernate.GrailsHibernateTemplate.get(GrailsHibernateTemplate.java:364) ~[grails-datastore-gorm-hibernate5-7.2.2.jar!/:?]
at org.grails.orm.hibernate.AbstractHibernateGormStaticApi.get(AbstractHibernateGormStaticApi.groovy:120) ~[grails-datastore-gorm-hibernate5-7.2.2.jar!/:?]
at org.grails.datastore.gorm.GormEntity$Trait$Helper.get(GormEntity.groovy:553) ~[grails-datastore-gorm-7.2.1.jar!/:?]
at org.grails.datastore.gorm.GormEntity$Trait$Helper$get$6.call(Unknown Source) ~[?:?]
at rundeck.ScheduledExecution.get(ScheduledExecution.groovy) ~[classes!/:?]
at rundeck.ScheduledExecution$get$11.call(Unknown Source) ~[?:?]
at rundeck.services.NotificationService$__tt__asyncTriggerJobNotification_closure21.doCall(NotificationService.groovy:197) ~[classes!/:?]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:107) ~[groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:323) ~[groovy-3.0.9.jar!/:3.0.9]
at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:274) ~[groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1035) ~[groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.Closure.call(Closure.java:412) ~[groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.Closure.call(Closure.java:428) ~[groovy-3.0.9.jar!/:3.0.9]
at grails.gorm.transactions.GrailsTransactionTemplate$2.doInTransaction(GrailsTransactionTemplate.groovy:94) ~[grails-datastore-gorm-7.2.1.jar!/:?]
at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140) ~[spring-tx-5.3.20.jar!/:5.3.20]
at grails.gorm.transactions.GrailsTransactionTemplate.execute(GrailsTransactionTemplate.groovy:91) ~[grails-datastore-gorm-7.2.1.jar!/:?]
at org.grails.datastore.gorm.GormStaticApi.withTransaction(GormStaticApi.groovy:1014) ~[grails-datastore-gorm-7.2.1.jar!/:?]
at org.grails.datastore.gorm.GormStaticApi.withTransaction(GormStaticApi.groovy:966) ~[grails-datastore-gorm-7.2.1.jar!/:?]
at org.grails.datastore.gorm.GormStaticApi.withNewTransaction(GormStaticApi.groovy:927) ~[grails-datastore-gorm-7.2.1.jar!/:?]
at org.grails.datastore.gorm.GormEntity$Trait$Helper.withNewTransaction(GormEntity.groovy:954) ~[grails-datastore-gorm-7.2.1.jar!/:?]
at org.grails.datastore.gorm.GormEntity$Trait$Helper$withNewTransaction$7.call(Unknown Source) ~[?:?]
at rundeck.ScheduledExecution.withNewTransaction(ScheduledExecution.groovy) ~[classes!/:?]
at rundeck.ScheduledExecution$withNewTransaction$12.call(Unknown Source) ~[?:?]
at rundeck.services.NotificationService.$tt__asyncTriggerJobNotification(NotificationService.groovy:196) ~[classes!/:?]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:107) ~[groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:323) ~[groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1268) ~[groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1035) ~[groovy-3.0.9.jar!/:3.0.9]
at org.codehaus.groovy.runtime.InvokerHelper.invokePogoMethod(InvokerHelper.java:1029) ~[groovy-3.0.9.jar!/:3.0.9]
at org.codehaus.groovy.runtime.InvokerHelper.invokeMethod(InvokerHelper.java:1012) ~[groovy-3.0.9.jar!/:3.0.9]
at org.codehaus.groovy.runtime.InvokerHelper.invokeMethodSafe(InvokerHelper.java:101) ~[groovy-3.0.9.jar!/:3.0.9]
at rundeck.services.NotificationService$_asyncTriggerJobNotification_closure6.doCall(NotificationService.groovy) ~[classes!/:?]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:107) ~[groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:323) ~[groovy-3.0.9.jar!/:3.0.9]
at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:274) ~[groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1035) ~[groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.Closure.call(Closure.java:412) ~[groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.Closure.call(Closure.java:428) ~[groovy-3.0.9.jar!/:3.0.9]
at grails.gorm.transactions.GrailsTransactionTemplate$2.doInTransaction(GrailsTransactionTemplate.groovy:94) ~[grails-datastore-gorm-7.2.1.jar!/:?]
at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140) ~[spring-tx-5.3.20.jar!/:5.3.20]
at grails.gorm.transactions.GrailsTransactionTemplate.execute(GrailsTransactionTemplate.groovy:91) ~[grails-datastore-gorm-7.2.1.jar!/:?]
at rundeck.services.NotificationService.asyncTriggerJobNotification(NotificationService.groovy) ~[classes!/:?]
at rundeck.services.NotificationService$asyncTriggerJobNotification.call(Unknown Source) ~[?:?]
at rundeck.services.ExecutionService.$tt__executeAsyncBegin(ExecutionService.groovy:1195) [classes!/:?]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:107) [groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:323) [groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1268) [groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1035) [groovy-3.0.9.jar!/:3.0.9]
at org.codehaus.groovy.runtime.InvokerHelper.invokePogoMethod(InvokerHelper.java:1029) [groovy-3.0.9.jar!/:3.0.9]
at org.codehaus.groovy.runtime.InvokerHelper.invokeMethod(InvokerHelper.java:1012) [groovy-3.0.9.jar!/:3.0.9]
at org.codehaus.groovy.runtime.InvokerHelper.invokeMethodSafe(InvokerHelper.java:101) [groovy-3.0.9.jar!/:3.0.9]
at rundeck.services.ExecutionService$_executeAsyncBegin_closure22.doCall(ExecutionService.groovy) [classes!/:?]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:107) [groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:323) [groovy-3.0.9.jar!/:3.0.9]
at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:274) [groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1035) [groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.Closure.call(Closure.java:412) [groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.Closure.call(Closure.java:428) [groovy-3.0.9.jar!/:3.0.9]
at grails.gorm.transactions.GrailsTransactionTemplate$2.doInTransaction(GrailsTransactionTemplate.groovy:94) [grails-datastore-gorm-7.2.1.jar!/:?]
at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140) [spring-tx-5.3.20.jar!/:5.3.20]
at grails.gorm.transactions.GrailsTransactionTemplate.execute(GrailsTransactionTemplate.groovy:91) [grails-datastore-gorm-7.2.1.jar!/:?]
at rundeck.services.ExecutionService.executeAsyncBegin(ExecutionService.groovy) [classes!/:?]
at rundeck.quartzjobs.ExecutionJob.executeCommand(ExecutionJob.groovy:370) [classes!/:?]
at rundeck.quartzjobs.ExecutionJob$executeCommand$2.callCurrent(Unknown Source) [classes!/:?]
at rundeck.quartzjobs.ExecutionJob.execute_internal(ExecutionJob.groovy:155) [classes!/:?]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:107) [groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:323) [groovy-3.0.9.jar!/:3.0.9]
at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:362) [groovy-3.0.9.jar!/:3.0.9]
at org.codehaus.groovy.runtime.callsite.PogoMetaClassSite.callCurrent(PogoMetaClassSite.java:61) [groovy-3.0.9.jar!/:3.0.9]
at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callCurrent(AbstractCallSite.java:185) [groovy-3.0.9.jar!/:3.0.9]
at rundeck.quartzjobs.ExecutionJob$_execute_closure1.doCall(ExecutionJob.groovy:100) [classes!/:?]
at rundeck.quartzjobs.ExecutionJob$_execute_closure1.doCall(ExecutionJob.groovy) [classes!/:?]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:107) [groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:323) [groovy-3.0.9.jar!/:3.0.9]
at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:274) [groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1035) [groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.Closure.call(Closure.java:412) [groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.Closure.call(Closure.java:406) [groovy-3.0.9.jar!/:3.0.9]
at groovy.lang.Closure.run(Closure.java:493) [groovy-3.0.9.jar!/:3.0.9]
at com.codahale.metrics.Timer.time(Timer.java:151) [metrics-core-4.2.9.jar!/:4.2.9]
at com.codahale.metrics.Timer$time$4.call(Unknown Source) [metrics-core-4.2.9.jar!/:?]
at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:47) [groovy-3.0.9.jar!/:3.0.9]
at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:125) [groovy-3.0.9.jar!/:3.0.9]
at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:139) [groovy-3.0.9.jar!/:3.0.9]
at rundeck.quartzjobs.ExecutionJob.execute(ExecutionJob.groovy:99) [classes!/:?]
at org.quartz.core.JobRunShell.run(JobRunShell.java:202) [quartz-2.3.2.jar!/:?]
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573) [quartz-2.3.2.jar!/:?]

rac...@rundeck.com

unread,
Feb 13, 2023, 4:12:45 PM2/13/23
to rundeck-discuss
Hi Brent,

Could you share the docker definition file to take a look? Please edit any potentially sensitive information.

Regards.

Brent Vaughn

unread,
Feb 13, 2023, 4:17:59 PM2/13/23
to rundeck-discuss

Dockerfile:

FROM rundeck/rundeck:4.8.0

RUN mkdir /home/rundeck/machine-nodes/

RUN cat /home/rundeck/docker-lib/entry.sh | grep '\-Dloginmodule.conf.name=jaas-loginmodule.conf' \
 && sed -i "s/-Dloginmodule.conf.name=jaas-loginmodule.conf/-Dloginmodule.conf.name=jaas-ldap.conf/" /home/rundeck/docker-lib/entry.sh
 
RUN cat /etc/remco/templates/rundeck-config.properties | grep 'rundeck.api.tokens.duration.max={{ getv("/rundeck/api/tokens/duration/max", "30d") }}'
RUN sed -i "s/rundeck.api.tokens.duration.max={{ getv(\"\/rundeck\/api\/tokens\/duration\/max\", \"30d\") }}/rundeck.api.tokens.duration.max={{ getv(\"\/rundeck\/api\/tokens\/duration\/max\", \"0\") }}/" /etc/remco/templates/rundeck-config.properties

COPY --chown=rundeck:root remco /etc/remco




Docker stack file:

version: '3.8'

networks:
swarm-network:
external: true

volumes:
rundeck-pg-data:
external: true

services:
postgres:
image: postgres
networks:
- swarm-network
volumes:
- rundeck-pg-data:/var/lib/postgresql/data
environment:
- POSTGRES_DATABASE=rundeck
- POSTGRES_USER=rundeck
- POSTGRES_PASSWORD=${RUNDECK_POSTGRES_PASSWORD}
- POSTGRES_ROOT_PASSWORD=${RUNDECK_POSTGRES_ROOT_PASSWORD}

rundeck:
image: ${IMAGE}
networks:
- swarm-network
environment:
- TZ=US/Central
- RUNDECK_GRAILS_URL=https://${SERVICE_DOMAIN}
- RUNDECK_SERVER_FORWARDED=true
- RUNDECK_MAIL_SMTP_HOST=${SMTP_HOST}
- RUNDECK_MAIL_SMTP_PORT=25
- RUNDECK_MAIL_FROM=run...@rundeck.climatecontrolgroup.com
- RUNDECK_DATABASE_URL=jdbc:postgresql://postgres/rundeck
- RUNDECK_DATABASE_DRIVER=org.postgresql.Driver
- RUNDECK_DATABASE_USERNAME=rundeck
- RUNDECK_DATABASE_PASSWORD=${RUNDECK_POSTGRES_PASSWORD}
- EXECUTION_MODE=${EXECUTION_MODE}
- RUNDECK_SA_PASSWORD=${RUNDECK_SA_PASSWORD}
volumes:
- ./conf/realm.properties:/home/rundeck/server/config/realm.properties
- ./conf/admin.aclpolicy:/home/rundeck/etc/admin.aclpolicy
- ./conf/apitoken.aclpolicy:/home/rundeck/etc/apitoken.aclpolicy
- ./conf/CLM-scart-image-upload.aclpolicy:/home/rundeck/etc/CLM-scart-image-upload.aclpolicy
- ./machine-nodes/scheduledjobs-resources.xml:/home/rundeck/machine-nodes/scheduledjobs-resources.xml
- ./machine-nodes/dockerbackups-resources.xml:/home/rundeck/machine-nodes/dockerbackups-resources.xml
- ./machine-nodes/dockercleanup-resources.xml:/home/rundeck/machine-nodes/dockercleanup-resources.xml

deploy: labels: - traefik.enable=true - traefik.http.services.rundeck.loadbalancer.server.port=4440 - traefik.http.routers.rundeck.rule=Host(`${SERVICE_DOMAIN}`) - traefik.http.routers.rundeck.entrypoints=http - traefik.http.routers.rundeck.middlewares=https-redirect@file - traefik.http.routers.rundeck-https.rule=Host(`${SERVICE_DOMAIN}`) - traefik.http.routers.rundeck-https.entrypoints=https - traefik.http.routers.rundeck-https.tls=true healthcheck: test: curl -L -s -o /dev/null http://localhost:4440 || exit 1 interval: 2m timeout: 10s retries: 5 start_period: 1m

Brent Vaughn

unread,
Feb 13, 2023, 4:23:08 PM2/13/23
to rundeck-discuss
I am also seeing this error message in the logs as well:

[2023-02-13T15:15:27,448] INFO  execution.status rundeck_sa finish [13941:succeeded] ScheduledJobs rundeck_sa/- "CLM/Update Quotes Job  -"[4de35206-36ca-45ac-9c37-5cc7ff98d04e]  
[2023-02-13T15:15:29,181] INFO  execution.status rundeck_sa finish [13946:succeeded] ScheduledJobs rundeck_sa/- "CLM/Update Warranty Limit Job  -"[a377b3d7-3e3c-4949-82f7-9daf577f500a]  
[2023-02-13T15:15:40,049] ERROR pool.ConnectionPool - Failed to re-connect connection [org.apache.tomcat.jdbc.pool.ConnectionPool@42f7185c] that expired because of maxAge
org.postgresql.util.PSQLException: FATAL: role "rundeck" does not exist
       at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2675) ~[postgresql-42.3.3.jar!/:42.3.3]
       at org.postgresql.core.v3.QueryExecutorImpl.readStartupMessages(QueryExecutorImpl.java:2787) ~[postgresql-42.3.3.jar!/:42.3.3]
       at org.postgresql.core.v3.QueryExecutorImpl.<init>(QueryExecutorImpl.java:173) ~[postgresql-42.3.3.jar!/:42.3.3]
       at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:290) ~[postgresql-42.3.3.jar!/:42.3.3]
       at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:49) ~[postgresql-42.3.3.jar!/:42.3.3]
       at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:223) ~[postgresql-42.3.3.jar!/:42.3.3]
       at org.postgresql.Driver.makeConnection(Driver.java:400) ~[postgresql-42.3.3.jar!/:42.3.3]
       at org.postgresql.Driver.connect(Driver.java:259) ~[postgresql-42.3.3.jar!/:42.3.3]
       at org.apache.tomcat.jdbc.pool.PooledConnection.connectUsingDriver(PooledConnection.java:319) ~[tomcat-jdbc-9.0.44.jar!/:?]
       at org.apache.tomcat.jdbc.pool.PooledConnection.connect(PooledConnection.java:212) ~[tomcat-jdbc-9.0.44.jar!/:?]
       at org.apache.tomcat.jdbc.pool.PooledConnection.reconnect(PooledConnection.java:372) ~[tomcat-jdbc-9.0.44.jar!/:?]
       at org.apache.tomcat.jdbc.pool.ConnectionPool.reconnectIfExpired(ConnectionPool.java:932) [tomcat-jdbc-9.0.44.jar!/:?]
       at org.apache.tomcat.jdbc.pool.ConnectionPool.testAllIdle(ConnectionPool.java:1138) [tomcat-jdbc-9.0.44.jar!/:?]
       at org.apache.tomcat.jdbc.pool.ConnectionPool$PoolCleaner.run(ConnectionPool.java:1529) [tomcat-jdbc-9.0.44.jar!/:?]
       at java.util.TimerThread.mainLoop(Timer.java:556) [?:?]
       at java.util.TimerThread.run(Timer.java:506) [?:?]


Brent Vaughn

unread,
Feb 13, 2023, 4:37:45 PM2/13/23
to rundeck-discuss
And here is another stack trace in the logs with the Postgres and Rundeck exceptions together:

[2023-02-13T15:20:00,335] ERROR spi.SqlExceptionHelper - FATAL: role "rundeck" does not exist
[2023-02-13T15:20:00,252] ERROR quartzjobs.ExecutionJob - Unable to start Job execution: could not prepare statement
org.hibernate.exception.GenericJDBCException: could not prepare statement
       at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:47) ~[hibernate-core-5.4.24.Final.jar!/:5.4.24.Final]
       at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113) ~[hibernate-core-5.4.24.Final.jar!/:5.4.24.Final]
       at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:186) ~[hibernate-core-5.4.24.Final.jar!/:5.4.24.Final]
       at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:151) ~[hibernate-core-5.4.24.Final.jar!/:5.4.24.Final]
       at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:2104) ~[hibernate-core-5.4.24.Final.jar!/:5.4.24.Final]
       at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:2041) ~[hibernate-core-5.4.24.Final.jar!/:5.4.24.Final]
       at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:2019) ~[hibernate-core-5.4.24.Final.jar!/:5.4.24.Final]
       at org.hibernate.loader.Loader.doQuery(Loader.java:948) ~[hibernate-core-5.4.24.Final.jar!/:5.4.24.Final]
       at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:349) ~[hibernate-core-5.4.24.Final.jar!/:5.4.24.Final]
       at org.hibernate.loader.Loader.doList(Loader.java:2850) ~[hibernate-core-5.4.24.Final.jar!/:5.4.24.Final]
       at org.hibernate.loader.Loader.doList(Loader.java:2832) ~[hibernate-core-5.4.24.Final.jar!/:5.4.24.Final]
       at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2664) ~[hibernate-core-5.4.24.Final.jar!/:5.4.24.Final]
       at org.hibernate.loader.Loader.list(Loader.java:2659) ~[hibernate-core-5.4.24.Final.jar!/:5.4.24.Final]
       at org.hibernate.loader.criteria.CriteriaLoader.list(CriteriaLoader.java:109) ~[hibernate-core-5.4.24.Final.jar!/:5.4.24.Final]
       at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1877) ~[hibernate-core-5.4.24.Final.jar!/:5.4.24.Final]
       at org.hibernate.internal.CriteriaImpl.list(CriteriaImpl.java:370) ~[hibernate-core-5.4.24.Final.jar!/:5.4.24.Final]
       at org.hibernate.internal.CriteriaImpl.uniqueResult(CriteriaImpl.java:392) ~[hibernate-core-5.4.24.Final.jar!/:5.4.24.Final]
       at grails.orm.HibernateCriteriaBuilder.executeUniqueResultWithProxyUnwrap(HibernateCriteriaBuilder.java:145) ~[grails-datastore-gorm-hibernate5-7.2.2.jar!/:?]
       at org.grails.orm.hibernate.query.AbstractHibernateCriteriaBuilder.invokeMethod(AbstractHibernateCriteriaBuilder.java:1703) ~[grails-datastore-gorm-hibernate5-7.2.2.jar!/:?]
       at org.grails.orm.hibernate.query.AbstractHibernateCriteriaBuilder.get(AbstractHibernateCriteriaBuilder.java:1585) ~[grails-datastore-gorm-hibernate5-7.2.2.jar!/:?]
       at org.grails.datastore.mapping.query.api.BuildableCriteria$get$0.call(Unknown Source) ~[?:?]
       at rundeck.services.ExecutionValidatorService.canRunMoreExecutions(ExecutionValidatorService.groovy:67) ~[classes!/:?]
       at com.dtolabs.rundeck.core.execution.ExecutionValidator$canRunMoreExecutions$0.call(Unknown Source) ~[?:?]
       at rundeck.services.ExecutionService.$pub__createExecution(ExecutionService.groovy:2540) ~[classes!/:?]
       at rundeck.services.ExecutionService.$tt__createExecution(ExecutionService.groovy) ~[classes!/:?]
       at jdk.internal.reflect.GeneratedMethodAccessor1267.invoke(Unknown Source) ~[?:?]
       at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
       at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
       at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:107) ~[groovy-3.0.9.jar!/:3.0.9]
       at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:323) ~[groovy-3.0.9.jar!/:3.0.9]
       at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1268) ~[groovy-3.0.9.jar!/:3.0.9]
       at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1035) ~[groovy-3.0.9.jar!/:3.0.9]
       at org.codehaus.groovy.runtime.InvokerHelper.invokePogoMethod(InvokerHelper.java:1029) ~[groovy-3.0.9.jar!/:3.0.9]
       at org.codehaus.groovy.runtime.InvokerHelper.invokeMethod(InvokerHelper.java:1012) ~[groovy-3.0.9.jar!/:3.0.9]
       at org.codehaus.groovy.runtime.InvokerHelper.invokeMethodSafe(InvokerHelper.java:101) ~[groovy-3.0.9.jar!/:3.0.9]
       at rundeck.services.ExecutionService$_createExecution_closure47.doCall(ExecutionService.groovy) ~[classes!/:?]
       at jdk.internal.reflect.GeneratedMethodAccessor1265.invoke(Unknown Source) ~[?:?]
       at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
       at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
       at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:107) ~[groovy-3.0.9.jar!/:3.0.9]
       at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:323) ~[groovy-3.0.9.jar!/:3.0.9]
       at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:274) ~[groovy-3.0.9.jar!/:3.0.9]
       at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1035) ~[groovy-3.0.9.jar!/:3.0.9]
       at groovy.lang.Closure.call(Closure.java:412) ~[groovy-3.0.9.jar!/:3.0.9]
       at groovy.lang.Closure.call(Closure.java:428) ~[groovy-3.0.9.jar!/:3.0.9]
       at grails.gorm.transactions.GrailsTransactionTemplate$2.doInTransaction(GrailsTransactionTemplate.groovy:94) ~[grails-datastore-gorm-7.2.1.jar!/:?]
       at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140) ~[spring-tx-5.3.20.jar!/:5.3.20]
       at grails.gorm.transactions.GrailsTransactionTemplate.execute(GrailsTransactionTemplate.groovy:91) ~[grails-datastore-gorm-7.2.1.jar!/:?]
       at rundeck.services.ExecutionService.createExecution(ExecutionService.groovy) ~[classes!/:?]
       at rundeck.services.ExecutionService.createExecution(ExecutionService.groovy) ~[classes!/:?]
       at rundeck.quartzjobs.ExecutionJob.initialize(ExecutionJob.groovy:344) ~[classes!/:?]
       at rundeck.quartzjobs.ExecutionJob$initialize.callCurrent(Unknown Source) ~[?:?]
       at rundeck.quartzjobs.ExecutionJob.execute_internal(ExecutionJob.groovy:121) [classes!/:?]
       at jdk.internal.reflect.GeneratedMethodAccessor1261.invoke(Unknown Source) ~[?:?]
       at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
       at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
       at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:107) [groovy-3.0.9.jar!/:3.0.9]
       at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:323) [groovy-3.0.9.jar!/:3.0.9]
       at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:362) [groovy-3.0.9.jar!/:3.0.9]
       at org.codehaus.groovy.runtime.callsite.PogoMetaClassSite.callCurrent(PogoMetaClassSite.java:61) [groovy-3.0.9.jar!/:3.0.9]
       at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callCurrent(AbstractCallSite.java:185) [groovy-3.0.9.jar!/:3.0.9]
       at rundeck.quartzjobs.ExecutionJob$_execute_closure1.doCall(ExecutionJob.groovy:100) [classes!/:?]
       at rundeck.quartzjobs.ExecutionJob$_execute_closure1.doCall(ExecutionJob.groovy) [classes!/:?]
       at jdk.internal.reflect.GeneratedMethodAccessor1260.invoke(Unknown Source) ~[?:?]
       at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
       at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
       at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:107) [groovy-3.0.9.jar!/:3.0.9]
       at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:323) [groovy-3.0.9.jar!/:3.0.9]
       at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:274) [groovy-3.0.9.jar!/:3.0.9]
       at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1035) [groovy-3.0.9.jar!/:3.0.9]
       at groovy.lang.Closure.call(Closure.java:412) [groovy-3.0.9.jar!/:3.0.9]
       at groovy.lang.Closure.call(Closure.java:406) [groovy-3.0.9.jar!/:3.0.9]
       at groovy.lang.Closure.run(Closure.java:493) [groovy-3.0.9.jar!/:3.0.9]
       at com.codahale.metrics.Timer.time(Timer.java:151) [metrics-core-4.2.9.jar!/:4.2.9]
       at com.codahale.metrics.Timer$time$1.call(Unknown Source) [metrics-core-4.2.9.jar!/:?]
       at rundeck.quartzjobs.ExecutionJob.execute(ExecutionJob.groovy:99) [classes!/:?]
       at org.quartz.core.JobRunShell.run(JobRunShell.java:202) [quartz-2.3.2.jar!/:?]
       at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573) [quartz-2.3.2.jar!/:?]
Caused by: org.postgresql.util.PSQLException: FATAL: role "rundeck" does not exist
       at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2675) ~[postgresql-42.3.3.jar!/:42.3.3]
       at org.postgresql.core.v3.QueryExecutorImpl.readStartupMessages(QueryExecutorImpl.java:2787) ~[postgresql-42.3.3.jar!/:42.3.3]
       at org.postgresql.core.v3.QueryExecutorImpl.<init>(QueryExecutorImpl.java:173) ~[postgresql-42.3.3.jar!/:42.3.3]
       at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:290) ~[postgresql-42.3.3.jar!/:42.3.3]
       at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:49) ~[postgresql-42.3.3.jar!/:42.3.3]
       at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:223) ~[postgresql-42.3.3.jar!/:42.3.3]
       at org.postgresql.Driver.makeConnection(Driver.java:400) ~[postgresql-42.3.3.jar!/:42.3.3]
       at org.postgresql.Driver.connect(Driver.java:259) ~[postgresql-42.3.3.jar!/:42.3.3]
       at org.apache.tomcat.jdbc.pool.PooledConnection.connectUsingDriver(PooledConnection.java:319) ~[tomcat-jdbc-9.0.44.jar!/:?]
       at org.apache.tomcat.jdbc.pool.PooledConnection.connect(PooledConnection.java:212) ~[tomcat-jdbc-9.0.44.jar!/:?]
       at org.apache.tomcat.jdbc.pool.ConnectionPool.createConnection(ConnectionPool.java:744) ~[tomcat-jdbc-9.0.44.jar!/:?]
       at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:676) ~[tomcat-jdbc-9.0.44.jar!/:?]
       at org.apache.tomcat.jdbc.pool.ConnectionPool.getConnection(ConnectionPool.java:198) ~[tomcat-jdbc-9.0.44.jar!/:?]
       at org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourceProxy.java:132) ~[tomcat-jdbc-9.0.44.jar!/:?]
       at org.springframework.jdbc.datasource.LazyConnectionDataSourceProxy$LazyConnectionInvocationHandler.getTargetConnection(LazyConnectionDataSourceProxy.java:405) ~[spring-jdbc-5.3.20.jar!/:5.3.20]
       at org.springframework.jdbc.datasource.LazyConnectionDataSourceProxy$LazyConnectionInvocationHandler.invoke(LazyConnectionDataSourceProxy.java:378) ~[spring-jdbc-5.3.20.jar!/:5.3.20]
       at com.sun.proxy.$Proxy189.prepareStatement(Unknown Source) ~[?:?]
       at jdk.internal.reflect.GeneratedMethodAccessor336.invoke(Unknown Source) ~[?:?]
       at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
       at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
       at org.springframework.jdbc.datasource.TransactionAwareDataSourceProxy$TransactionAwareInvocationHandler.invoke(TransactionAwareDataSourceProxy.java:238) ~[spring-jdbc-5.3.20.jar!/:5.3.20]
       at com.sun.proxy.$Proxy189.prepareStatement(Unknown Source) ~[?:?]
       at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:149) ~[hibernate-core-5.4.24.Final.jar!/:5.4.24.Final]
       at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:176) ~[hibernate-core-5.4.24.Final.jar!/:5.4.24.Final]
       ... 75 more


rac...@rundeck.com

unread,
Feb 14, 2023, 7:40:25 AM2/14/23
to rundeck-discuss
Hi!

I'm trying to replicate your scenario. What version of PostgreSQL are you using?Also, Is an "upgraded" Rundeck instance? (e.g: upgraded from Rundeck 4.7.0).

Regards!

Brent Vaughn

unread,
Feb 14, 2023, 8:55:33 AM2/14/23
to rundeck-discuss
Postgres 15.2 docker image is the database.

It was a brand new install.  I started out at Rundeck 4.9.0 from docker. Once I realized it wasn't working, I downgraded the Rundeck docker image to 4.8.0. 

rac...@rundeck.com

unread,
Feb 14, 2023, 3:16:11 PM2/14/23
to rundeck-discuss
Hi Brent,

Regarding this:

org.postgresql.util.PSQLException: FATAL: role "rundeck" does not exist

It seems that the "rundeck" role (or DB) isn't created in the PostgreSQL backend. Take a look at this.

Anyway, attached to this message I left a docker-compose example file to test (it uses Rundeck 4.10 + PostgreSQL 15.2).

Here you can see the steps regarding the PostgreSQL configuration.

Hope it helps!
docker-compose.yml

Brent Vaughn

unread,
Feb 17, 2023, 5:42:38 PM2/17/23
to rundeck-discuss
I just switched to using Mysql instead of Postgres and it just worked. 
Reply all
Reply to author
Forward
0 new messages