DependencyTrack / dependency-track

Dependency-Track is an intelligent Component Analysis platform that allows organizations to identify and reduce risk in the software supply chain.
https://dependencytrack.org/
Apache License 2.0
2.61k stars 553 forks source link

JDODataStoreExceptions after startup #2141

Closed valentijnscholten closed 3 weeks ago

valentijnscholten commented 1 year ago

Current Behavior

I have now seen 3 occasions of the below problem, maybe someone recognizes this.

We're running DT 4.6.2 in docker in ECS with postgres RDS instances as datastore and a volume for the DT /data directory.

Every week updates are installed on the Docker host OS (EC2, Debian 11). This usually triggers an EC2 restart, and thus a docker restart.

The containers come up succesfully and users can browse DT from the UI. Also most API calls work fine, but not all of them.

Example 1: /api/v1/project/lookup

Everything seems to be working, except /api/v1/lookup?name=bla&version=xyz:

2022-11-02 21:06:23,000 ERROR [GlobalExceptionHandler] Uncaught internal server error
javax.jdo.JDODataStoreException: Iteration request failed : SELECT 'alpine.model.Team' AS "DN_TYPE",,"A1"."ID""A1"."ID","A1"."NAME""A1"."NAME" AS "NUCORDER0",,"A1"."UUID","A1"."UUID", FROM  FROM "APIKEYS_TEAMS" "A0" INNER JOIN "TEAM" "A1" ON "A0"."TEAM_ID" = "A1"."ID" WHERE  INNER JOIN "TEAM" "A1" ON "A0"."TEAM_ID" = "A1"."ID" WHERE EXISTS (SELECT 'alpine.model.ApiKey''alpine.model.ApiKey' AS "DN_TYPE", AS "DN_TYPE","A0_SUB"."ID""A0_SUB"."ID" AS "DN_APPID" FROM "APIKEY" "A0_SUB""APIKEY" "A0_SUB" WHERE "A0_SUB"."APIKEY" = ? AND "A0"."APIKEY_ID" = "A0_SUB"."ID""A0_SUB"."APIKEY" = ? AND "A0"."APIKEY_ID" = "A0_SUB"."ID") ORDER BY "NUCORDER0"EXISTS (SELECT 'alpine.model.ApiKey''alpine.model.ApiKey' AS "DN_TYPE", AS "DN_TYPE","A0_SUB"."ID""A0_SUB"."ID" AS "DN_APPID" FROM "APIKEY" "A0_SUB""APIKEY" "A0_SUB" WHERE "A0_SUB"."APIKEY" = ? AND "A0"."APIKEY_ID" = "A0_SUB"."ID""A0_SUB"."APIKEY" = ? AND "A0"."APIKEY_ID" = "A0_SUB"."ID") ORDER BY "NUCORDER0"
        at org.datanucleus.api.jdo.JDOAdapter.getJDOExceptionForNucleusException(JDOAdapter.java:605)
        at org.datanucleus.api.jdo.JDOQuery.executeInternal(JDOQuery.java:456)
        at org.datanucleus.api.jdo.JDOQuery.execute(JDOQuery.java:276)
        at alpine.persistence.AlpineQueryManager.getApiKey(AlpineQueryManager.java:102)
        at alpine.server.auth.ApiKeyAuthenticationService.authenticate(ApiKeyAuthenticationService.java:67)
...
Caused by: org.postgresql.util.PSQLException: No value specified for parameter 2.
        at org.postgresql.core.v3.SimpleParameterList.checkAllParametersSet(SimpleParameterList.java:284)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:340)
        at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:496)
        at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:413)

Other calls, using the same API Key value, are working fine.

This code is in the Alpine framework and about retrieving an APIKey. However the query contains only 1 parameter:

https://github.com/stevespringett/Alpine/blob/157958bfe7fa5ad95e653667f7ce3282aed23af1/alpine-infra/src/main/java/alpine/persistence/AlpineQueryManager.java#L100-L104

permalink doesn't work it seems, here's the code:

    public ApiKey getApiKey(final String key) {
        final Query query = pm.newQuery(ApiKey.class, "key == :key");
        final List<ApiKey> result = (List<ApiKey>) query.execute(key);
        return Collections.isEmpty(result) ? null : result.get(0);
    }

Which should be translated by datanucleus into 2 parameters in the SQL query seen above. So it's a mystery how parameter 1 can be set, but parameter 2 can be empty.

I spent some time digging around, but couldn't explain this. So decided to take a professional approach: restart docker (so both containers).

This solved the problem.

Example 2: /api/v1/project/

Everything seems to be working, except /api/v1/project/:

curl -X 'GET' \
  'https://dependencytrack-eindhoven.isaac.nl/api/v1/project/yy' \
  -H 'accept: application/json' \
  -H 'X-Api-Key: xx'  
Uncaught internal server error

Exception

2022-11-08 00:00:02,614 [] ERROR [alpine.server.resources.GlobalExceptionHandler] Uncaught internal server error
javax.jdo.JDODataStoreException: Iteration request failed : SELECT 'alpine.model.Team''alpine.model.Team' AS "DN_TYPE","A1"."ID""A1"."ID","A1"."NAME""A1"."NAME" AS "NUCORDER0",,"A1"."UUID","A0"
."PROJECT_ID""A0"."PROJECT_ID" FROM  FROM "PROJECT_ACCESS_TEAMS" "A0" INNER JOIN "TEAM" "A1" ON "A0"."TEAM_ID" = "A1"."ID" WHERE  INNER JOIN "TEAM" "A1" ON "A0"."TEAM_ID" = "A1"."ID" WHERE EXIS
TS (SELECT 'org.dependencytrack.model.Project''org.dependencytrack.model.Project' AS "DN_TYPE" AS "DN_TYPE",,"A0_SUB"."ID" AS "DN_APPID" FROM  FROM "PROJECT" "A0_SUB""PROJECT" "A0_SUB" WHERE "A
0_SUB"."UUID" = ? AND "A0"."PROJECT_ID" = "A0_SUB"."ID") ORDER BY "NUCORDER0"EXISTS (SELECT 'org.dependencytrack.model.Project''org.dependencytrack.model.Project' AS "DN_TYPE" AS "DN_TYPE",,"A0
_SUB"."ID" AS "DN_APPID" FROM  FROM "PROJECT" "A0_SUB""PROJECT" "A0_SUB" WHERE "A0_SUB"."UUID" = ? AND "A0"."PROJECT_ID" = "A0_SUB"."ID") ORDER BY "NUCORDER0"
        at org.datanucleus.api.jdo.JDOAdapter.getJDOExceptionForNucleusException(JDOAdapter.java:605)
        at org.datanucleus.api.jdo.JDOQuery.executeInternal(JDOQuery.java:456)
        at org.datanucleus.api.jdo.JDOQuery.execute(JDOQuery.java:276)
        at alpine.persistence.AbstractAlpineQueryManager.getObjectByUuid(AbstractAlpineQueryManager.java:549)
        at alpine.persistence.AbstractAlpineQueryManager.getObjectByUuid(AbstractAlpineQueryManager.java:563)
        at org.dependencytrack.resources.v1.ProjectResource.getProject(ProjectResource.java:113)

...

Caused by: org.postgresql.util.PSQLException: No value specified for parameter 2.
        at org.postgresql.core.v3.SimpleParameterList.checkAllParametersSet(SimpleParameterList.java:284)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:340)

Again this doesn't make sense as there is only 1 paramater uuid, and again parameter 2 is considered empty?

Restarted docker, problem solved.

Example 3: /api/v1/project/lookup (again)

Everything seems to be working, except /api/v1/project/lookup?name=valentijn&version=master:

curl -X 'GET' \
  'https://deptrack/api/v1/project/lookup?name=some%2Fmiddleware+%28java%29&version=master' \
  -H 'accept: application/json' \
  -H 'X-Api-Key: xx'

Uncaught internal server error

Exception

2022-11-10 09:19:35,979 [] ERROR [alpine.server.resources.GlobalExceptionHandler] Uncaught internal server error
javax.jdo.JDODataStoreException: Iteration request failed : SELECT 'org.dependencytrack.model.Tag' AS "DN_TYPE","A1"."ID","A1"."NAME" AS "NUCORDER0","A0"."PROJECT_ID" FROM "PROJECTS_TAGS" "
A0" INNER JOIN "TAG" "A1" ON "A0"."TAG_ID" = "A1"."ID" WHERE EXISTS (SELECT 'org.dependencytrack.model.Project' AS "DN_TYPE","A0_SUB"."ID" AS "DN_APPID" FROM "PROJECT" "A0_SUB" WHERE "A0_SU
B"."NAME" = ? AND "A0_SUB"."VERSION" = ? AND "A0"."PROJECT_ID" = "A0_SUB"."ID") ORDER BY "NUCORDER0"'org.dependencytrack.model.Tag' AS "DN_TYPE","A1"."ID","A1"."NAME" AS "NUCORDER0","A0"."P
ROJECT_ID","A1"."NAME" AS "NUCORDER0" FROM "PROJECTS_TAGS" "A0" INNER JOIN "TAG" "A1" ON "A0"."TAG_ID" = "A1"."ID" WHERE EXISTS (SELECT 'org.dependencytrack.model.Project' AS "DN_TYPE","A0_
SUB"."ID" AS "DN_APPID" FROM "PROJECT" "A0_SUB" WHERE "A0_SUB"."NAME" = ? AND "A0_SUB"."VERSION" = ? AND "A0"."PROJECT_ID" = "A0_SUB"."ID") ORDER BY "NUCORDER0"
        at org.datanucleus.api.jdo.JDOAdapter.getJDOExceptionForNucleusException(JDOAdapter.java:605)
        at org.datanucleus.api.jdo.JDOQuery.executeInternal(JDOQuery.java:456)
        at org.datanucleus.api.jdo.JDOQuery.executeWithMap(JDOQuery.java:331)
        at org.dependencytrack.persistence.ProjectQueryManager.getProject(ProjectQueryManager.java:198)
        at org.dependencytrack.persistence.QueryManager.getProject(QueryManager.java:340)
        at org.dependencytrack.resources.v1.ProjectResource.getProject(ProjectResource.java:145)

...

Caused by: org.postgresql.util.PSQLException: No value specified for parameter 3.
        at org.postgresql.core.v3.SimpleParameterList.checkAllParametersSet(SimpleParameterList.java:284)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:340)

Parameter 3 is the version. Which is set and should be present in the query as it's mandatory. If I remove the version from the url, it works. DT says project cannot be found. But I haven't checked if that is the actual query returning nothing, or an early exit because the version is mandatory.

Anyway, I already knew a restart would probably fix it, so I gathered some logs and restarted docker again.

Solution

Anyone has any ideas / suggestions?

I realize this might not be a bug in DT nor in Alpine, but maybe others are seeing the same or have some suggestions.

It is not a resourcing issue as this instance is mostly idle with only 1 nightly job to upload 100 BOMs. And a nightly job that retrieves all projects to load them into backstage.

It seems that once the instance is running OK, the problem stays away and it only occurs after a restart.

I have 11 instances of DT, only 1 instances has the above problem. But it's also the only one under heave read load from backstage indexing.

Valentijn

Dependency-Track Version

4.6.2 / docker / ECS / RDS / PostgreSQL 13.7

Full stacktraces ``` 2022-11-02 21:06:23,000 ERROR [GlobalExceptionHandler] Uncaught internal server error javax.jdo.JDODataStoreException: Iteration request failed : SELECT 'alpine.model.Team' AS "DN_TYPE",,"A1"."ID""A1"."ID","A1"."NAME""A1"."NAME" AS "NUCORDER0",,"A1"."UUID","A1"."UUID", FROM FROM "APIKEYS_TEAMS" "A0" INNER JOIN "TEAM" "A1" ON "A0"."TEAM_ID" = "A1"."ID" WHERE INNER JOIN "TEAM" "A1" ON "A0"."TEAM_ID" = "A1"."ID" WHERE EXISTS (SELECT 'alpine.model.ApiKey''alpine.model.ApiKey' AS "DN_TYPE", AS "DN_TYPE","A0_SUB"."ID""A0_SUB"."ID" AS "DN_APPID" FROM "APIKEY" "A0_SUB""APIKEY" "A0_SUB" WHERE "A0_SUB"."APIKEY" = ? AND "A0"."APIKEY_ID" = "A0_SUB"."ID""A0_SUB"."APIKEY" = ? AND "A0"."APIKEY_ID" = "A0_SUB"."ID") ORDER BY "NUCORDER0"EXISTS (SELECT 'alpine.model.ApiKey''alpine.model.ApiKey' AS "DN_TYPE", AS "DN_TYPE","A0_SUB"."ID""A0_SUB"."ID" AS "DN_APPID" FROM "APIKEY" "A0_SUB""APIKEY" "A0_SUB" WHERE "A0_SUB"."APIKEY" = ? AND "A0"."APIKEY_ID" = "A0_SUB"."ID""A0_SUB"."APIKEY" = ? AND "A0"."APIKEY_ID" = "A0_SUB"."ID") ORDER BY "NUCORDER0" at org.datanucleus.api.jdo.JDOAdapter.getJDOExceptionForNucleusException(JDOAdapter.java:605) at org.datanucleus.api.jdo.JDOQuery.executeInternal(JDOQuery.java:456) at org.datanucleus.api.jdo.JDOQuery.execute(JDOQuery.java:276) at alpine.persistence.AlpineQueryManager.getApiKey(AlpineQueryManager.java:102) at alpine.server.auth.ApiKeyAuthenticationService.authenticate(ApiKeyAuthenticationService.java:67) at alpine.server.filters.AuthenticationFilter.filter(AuthenticationFilter.java:68) at org.glassfish.jersey.server.ContainerFilteringStage.apply(ContainerFilteringStage.java:108) at org.glassfish.jersey.server.ContainerFilteringStage.apply(ContainerFilteringStage.java:44) at org.glassfish.jersey.process.internal.Stages.process(Stages.java:173) at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:247) at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248) at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244) at org.glassfish.jersey.internal.Errors.process(Errors.java:292) at org.glassfish.jersey.internal.Errors.process(Errors.java:274) at org.glassfish.jersey.internal.Errors.process(Errors.java:244) at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:265) at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:234) at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:684) at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:394) at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:346) at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:358) at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:311) at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:205) at org.eclipse.jetty.servlet.ServletHolder$NotAsync.service(ServletHolder.java:1419) at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:764) at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1665) at alpine.server.filters.ContentSecurityPolicyFilter.doFilter(ContentSecurityPolicyFilter.java:225) at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:202) at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1635) at alpine.server.filters.ClickjackingFilter.doFilter(ClickjackingFilter.java:93) at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:202) at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1635) at alpine.server.filters.WhitelistUrlFilter.doFilter(WhitelistUrlFilter.java:166) at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:210) at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1635) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:527) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:131) at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:578) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122) at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:223) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1571) at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:221) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1383) at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:176) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:484) at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1544) at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:174) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1305) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:129) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122) at org.eclipse.jetty.server.Server.handle(Server.java:563) at org.eclipse.jetty.server.HttpChannel.lambda$handle$0(HttpChannel.java:505) at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:762) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:497) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:282) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:314) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100) at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53) at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.runTask(AdaptiveExecutionStrategy.java:421) at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.consumeTask(AdaptiveExecutionStrategy.java:390) at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.tryProduce(AdaptiveExecutionStrategy.java:277) at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.lambda$new$0(AdaptiveExecutionStrategy.java:139) at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:411) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:933) at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1077) at java.base/java.lang.Thread.run(Unknown Source) Caused by: org.postgresql.util.PSQLException: No value specified for parameter 2. at org.postgresql.core.v3.SimpleParameterList.checkAllParametersSet(SimpleParameterList.java:284) at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:340) at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:496) at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:413) at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:190) at org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:134) at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeQuery(ProxyPreparedStatement.java:52) at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeQuery(HikariProxyPreparedStatement.java) at org.datanucleus.store.rdbms.SQLController.executeStatementQuery(SQLController.java:548) at org.datanucleus.store.rdbms.query.JDOQLQuery.performExecute(JDOQLQuery.java:717) at org.datanucleus.store.query.Query.executeQuery(Query.java:2004) at org.datanucleus.store.query.Query.executeWithArray(Query.java:1893) at org.datanucleus.api.jdo.JDOQuery.executeInternal(JDOQuery.java:433) ... 64 common frames omitted ``` ``` 2022-11-08 00:00:02,614 [] ERROR [alpine.server.resources.GlobalExceptionHandler] Uncaught internal server error javax.jdo.JDODataStoreException: Iteration request failed : SELECT 'alpine.model.Team''alpine.model.Team' AS "DN_TYPE","A1"."ID""A1"."ID","A1"."NAME""A1"."NAME" AS "NUCORDER0",,"A1"."UUID","A0" ."PROJECT_ID""A0"."PROJECT_ID" FROM FROM "PROJECT_ACCESS_TEAMS" "A0" INNER JOIN "TEAM" "A1" ON "A0"."TEAM_ID" = "A1"."ID" WHERE INNER JOIN "TEAM" "A1" ON "A0"."TEAM_ID" = "A1"."ID" WHERE EXIS TS (SELECT 'org.dependencytrack.model.Project''org.dependencytrack.model.Project' AS "DN_TYPE" AS "DN_TYPE",,"A0_SUB"."ID" AS "DN_APPID" FROM FROM "PROJECT" "A0_SUB""PROJECT" "A0_SUB" WHERE "A 0_SUB"."UUID" = ? AND "A0"."PROJECT_ID" = "A0_SUB"."ID") ORDER BY "NUCORDER0"EXISTS (SELECT 'org.dependencytrack.model.Project''org.dependencytrack.model.Project' AS "DN_TYPE" AS "DN_TYPE",,"A0 _SUB"."ID" AS "DN_APPID" FROM FROM "PROJECT" "A0_SUB""PROJECT" "A0_SUB" WHERE "A0_SUB"."UUID" = ? AND "A0"."PROJECT_ID" = "A0_SUB"."ID") ORDER BY "NUCORDER0" at org.datanucleus.api.jdo.JDOAdapter.getJDOExceptionForNucleusException(JDOAdapter.java:605) at org.datanucleus.api.jdo.JDOQuery.executeInternal(JDOQuery.java:456) at org.datanucleus.api.jdo.JDOQuery.execute(JDOQuery.java:276) at alpine.persistence.AbstractAlpineQueryManager.getObjectByUuid(AbstractAlpineQueryManager.java:549) at alpine.persistence.AbstractAlpineQueryManager.getObjectByUuid(AbstractAlpineQueryManager.java:563) at org.dependencytrack.resources.v1.ProjectResource.getProject(ProjectResource.java:113) at jdk.internal.reflect.GeneratedMethodAccessor232.invoke(Unknown Source) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) at java.base/java.lang.reflect.Method.invoke(Unknown Source) at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:52) at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:134) at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:177) at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:176) at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:81) at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:478) at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:400) at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:81) at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:255) at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248) at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244) at org.glassfish.jersey.internal.Errors.process(Errors.java:292) at org.glassfish.jersey.internal.Errors.process(Errors.java:274) at org.glassfish.jersey.internal.Errors.process(Errors.java:244) at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:265) at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:234) at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:684) at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:394) at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:346) at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:358) at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:311) at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:205) at org.eclipse.jetty.servlet.ServletHolder$NotAsync.service(ServletHolder.java:1419) at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:764) at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1665) at alpine.server.filters.ContentSecurityPolicyFilter.doFilter(ContentSecurityPolicyFilter.java:225) at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:202) at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1635) at alpine.server.filters.ClickjackingFilter.doFilter(ClickjackingFilter.java:93) at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:202) at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1635) at alpine.server.filters.WhitelistUrlFilter.doFilter(WhitelistUrlFilter.java:166) at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:210) at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1635) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:527) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:131) at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:578) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122) at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:223) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1571) at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:221) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1383) at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:176) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:484) at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1544) at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:174) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1305) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:129) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122) at org.eclipse.jetty.server.Server.handle(Server.java:563) at org.eclipse.jetty.server.HttpChannel.lambda$handle$0(HttpChannel.java:505) at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:762) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:497) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:282) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:314) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100) at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53) at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.runTask(AdaptiveExecutionStrategy.java:421) at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.consumeTask(AdaptiveExecutionStrategy.java:390) at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.tryProduce(AdaptiveExecutionStrategy.java:277) at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.lambda$new$0(AdaptiveExecutionStrategy.java:139) at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:411) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:933) at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1077) at java.base/java.lang.Thread.run(Unknown Source) Caused by: org.postgresql.util.PSQLException: No value specified for parameter 2. at org.postgresql.core.v3.SimpleParameterList.checkAllParametersSet(SimpleParameterList.java:284) at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:340) at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:496) at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:413) at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:190) at org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:134) at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeQuery(ProxyPreparedStatement.java:52) at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeQuery(HikariProxyPreparedStatement.java) at org.datanucleus.store.rdbms.SQLController.executeStatementQuery(SQLController.java:548) at org.datanucleus.store.rdbms.query.JDOQLQuery.performExecute(JDOQLQuery.java:717) at org.datanucleus.store.query.Query.executeQuery(Query.java:2004) at org.datanucleus.store.query.Query.executeWithArray(Query.java:1893) at org.datanucleus.api.jdo.JDOQuery.executeInternal(JDOQuery.java:433) ... 72 common frames omitted ``` ``` 2022-11-10 09:19:35,979 [] ERROR [alpine.server.resources.GlobalExceptionHandler] Uncaught internal server error javax.jdo.JDODataStoreException: Iteration request failed : SELECT 'org.dependencytrack.model.Tag' AS "DN_TYPE","A1"."ID","A1"."NAME" AS "NUCORDER0","A0"."PROJECT_ID" FROM "PROJECTS_TAGS" " A0" INNER JOIN "TAG" "A1" ON "A0"."TAG_ID" = "A1"."ID" WHERE EXISTS (SELECT 'org.dependencytrack.model.Project' AS "DN_TYPE","A0_SUB"."ID" AS "DN_APPID" FROM "PROJECT" "A0_SUB" WHERE "A0_SU B"."NAME" = ? AND "A0_SUB"."VERSION" = ? AND "A0"."PROJECT_ID" = "A0_SUB"."ID") ORDER BY "NUCORDER0"'org.dependencytrack.model.Tag' AS "DN_TYPE","A1"."ID","A1"."NAME" AS "NUCORDER0","A0"."P ROJECT_ID","A1"."NAME" AS "NUCORDER0" FROM "PROJECTS_TAGS" "A0" INNER JOIN "TAG" "A1" ON "A0"."TAG_ID" = "A1"."ID" WHERE EXISTS (SELECT 'org.dependencytrack.model.Project' AS "DN_TYPE","A0_ SUB"."ID" AS "DN_APPID" FROM "PROJECT" "A0_SUB" WHERE "A0_SUB"."NAME" = ? AND "A0_SUB"."VERSION" = ? AND "A0"."PROJECT_ID" = "A0_SUB"."ID") ORDER BY "NUCORDER0" at org.datanucleus.api.jdo.JDOAdapter.getJDOExceptionForNucleusException(JDOAdapter.java:605) at org.datanucleus.api.jdo.JDOQuery.executeInternal(JDOQuery.java:456) at org.datanucleus.api.jdo.JDOQuery.executeWithMap(JDOQuery.java:331) at org.dependencytrack.persistence.ProjectQueryManager.getProject(ProjectQueryManager.java:198) at org.dependencytrack.persistence.QueryManager.getProject(QueryManager.java:340) at org.dependencytrack.resources.v1.ProjectResource.getProject(ProjectResource.java:145) at jdk.internal.reflect.GeneratedMethodAccessor134.invoke(Unknown Source) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) at java.base/java.lang.reflect.Method.invoke(Unknown Source) at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:52) at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:134) at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:177) at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:176) at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:81) at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:478) at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:400) at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:81) at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:255) at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248) at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244) at org.glassfish.jersey.internal.Errors.process(Errors.java:292) at org.glassfish.jersey.internal.Errors.process(Errors.java:274) at org.glassfish.jersey.internal.Errors.process(Errors.java:244) at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:265) at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:234) at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:684) at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:394) at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:346) at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:358) at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:311) at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:205) at org.eclipse.jetty.servlet.ServletHolder$NotAsync.service(ServletHolder.java:1419) at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:764) at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1665) at alpine.server.filters.ContentSecurityPolicyFilter.doFilter(ContentSecurityPolicyFilter.java:225) at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:202) at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1635) at alpine.server.filters.ClickjackingFilter.doFilter(ClickjackingFilter.java:93) at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:202) at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1635) at alpine.server.filters.WhitelistUrlFilter.doFilter(WhitelistUrlFilter.java:166) at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:210) at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1635) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:527) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:131) at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:578) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122) at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:223) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1571) at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:221) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1383) at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:176) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:484) at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1544) at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:174) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1305) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:129) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122) at org.eclipse.jetty.server.Server.handle(Server.java:563) at org.eclipse.jetty.server.HttpChannel.lambda$handle$0(HttpChannel.java:505) at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:762) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:497) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:282) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:314) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100) at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53) at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.runTask(AdaptiveExecutionStrategy.java:421) at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.consumeTask(AdaptiveExecutionStrategy.java:390) at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.tryProduce(AdaptiveExecutionStrategy.java:277) at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.lambda$new$0(AdaptiveExecutionStrategy.java:139) at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:411) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:933) at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1077) at java.base/java.lang.Thread.run(Unknown Source) Caused by: org.postgresql.util.PSQLException: No value specified for parameter 3. at org.postgresql.core.v3.SimpleParameterList.checkAllParametersSet(SimpleParameterList.java:284) at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:340) at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:496) at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:413) at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:190) at org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:134) at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeQuery(ProxyPreparedStatement.java:52) at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeQuery(HikariProxyPreparedStatement.java) at org.datanucleus.store.rdbms.SQLController.executeStatementQuery(SQLController.java:548) at org.datanucleus.store.rdbms.query.JDOQLQuery.performExecute(JDOQLQuery.java:717) at org.datanucleus.store.query.Query.executeQuery(Query.java:2004) at org.datanucleus.store.query.Query.executeWithMap(Query.java:1911) at org.datanucleus.api.jdo.JDOQuery.executeInternal(JDOQuery.java:437) ... 72 common frames omitted ```
nscuro commented 1 year ago

Taking a wild guess here, this really looks like an issue in DataNucleus' query compilation and / or caching.

The fact that the issue persists after it occurred for the first time, but is fixable by a restart strongly suggests that the query caching is playing a role.

valentijnscholten commented 1 year ago

Initialization of those caches maybe. It happened now every time we installed Debian updates on the host and restarted the host. Possibly since the upgrade to 4.6.x. I wonder what could cause the initialization of something to fail. The database is remote in RDS and available all the time. Will try to enable DEBUG logging for datanucleus. Looking at the code they are logging parameters etc, so that might give a clue and/or more information to log an issue at datanucleus.

valentijnscholten commented 1 year ago

Had another occurrence, this time with another exception:

javax.jdo.JDODataStoreException: Iteration request failed : SELECT 'alpine.model.Team' AS "DN_TYPE",,,,"A1"."NAME""A1"."NAME" AS "NUCORDER0",,"A1"."UUID""A1"."UUID","A0"."APIKEY_ID" FROM  FROM "APIKEYS_TEAMS" "A0" INNER JOIN "TEAM" "A1" ON "A0"."TEAM_ID" = "A1"."ID" INNER JOIN "TEAM" "A1" ON "A0"."TEAM_ID" = "A1"."ID" WHERE  WHERE EXISTS (SELECT 'alpine.model.ApiKey''alpine.model.ApiKey' AS "DN_TYPE", AS "DN_TYPE","A0_SUB"."ID" AS "DN_APPID" AS "DN_APPID" FROM "APIKEY" "A0_SUB" WHERE "A0_SUB"."APIKEY" = ? AND "A0"."APIKEY_ID" = "A0_SUB"."ID""A0_SUB"."APIKEY" = ? AND "A0"."APIKEY_ID" = "A0_SUB"."ID") ORDER BY "NUCORDER0"EXISTS (SELECT 'alpine.model.ApiKey''alpine.model.ApiKey' AS "DN_TYPE", AS "DN_TYPE","A0_SUB"."ID" AS "DN_APPID" AS "DN_APPID" FROM "APIKEY" "A0_SUB" WHERE "A0_SUB"."APIKEY" = ? AND "A0"."APIKEY_ID" = "A0_SUB"."ID""A0_SUB"."APIKEY" = ? AND "A0"."APIKEY_ID" = "A0_SUB"."ID") ORDER BY "NUCORDER0"

Which seems to have been reported before in #409 and #422. One of them refers to increasing / decreasing timeouts. Since my issue occurs right after a reboot it's probably not related to session timeouts.

engineerakki commented 6 months ago

Got this same behaviour on DependencyTrack 4.9.1

The lookup api /api/v1/project/lookup suddenly started returning Uncaught internal server error with statuscode 500.

Simultenously the logs in DT api-server has following error:

javax.jdo.JDODataStoreException: Iteration request failed : SELECT 'org.dependencytrack.model.ProjectProperty' AS "DN_TYPE","A0"."DESCRIPTION","A0"."GROUPNAME" AS "NUCORDER0","A0"."ID","A0"."PROPERTYNAME" AS "NUCORDER1","A0"."PROPERTYTYPE","A0"."PROPERTYVALUE","A0"."PROJECT_ID" FROM "PROJECT_PROPERTY" "A0" WHERE EXISTS (SELECT 'org.dependencytrack.model.Project' AS "DN_TYPE","A0_SUB"."ID" AS "DN_APPID" FROM "PROJECT" "A0_SUB" WHERE "A0_SUB"."NAME" = ? AND "A0_SUB"."VERSION" = ? AND "A0"."PROJECT_ID" = "A0_SUB"."ID") ORDER BY "NUCORDER0","NUCORDER1"'org.dependencytrack.model.ProjectProperty' AS "DN_TYPE","A0"."DESCRIPTION","A0"."GROUPNAME" AS "NUCORDER0","A0"."ID","A0"."PROPERTYNAME" AS "NUCORDER1","A0"."PROPERTYTYPE","A0"."PROPERTYVALUE","A0"."PROJECT_ID","A0"."PROPERTYNAME" AS "NUCORDER1" FROM "PROJECT_PROPERTY" "A0" WHERE EXISTS (SELECT 'org.dependencytrack.model.Project' AS "DN_TYPE","A0_SUB"."ID" AS "DN_APPID" FROM "PROJECT" "A0_SUB" WHERE "A0_SUB"."NAME" = ? AND "A0_SUB"."VERSION" = ? AND "A0"."PROJECT_ID" = "A0_SUB"."ID") ORDER BY "NUCORDER0","NUCORDER1"
    at org.datanucleus.api.jdo.JDOAdapter.getJDOExceptionForNucleusException(JDOAdapter.java:605)
    at org.datanucleus.api.jdo.JDOQuery.executeInternal(JDOQuery.java:456)
    at org.datanucleus.api.jdo.JDOQuery.executeWithMap(JDOQuery.java:331)
    at org.dependencytrack.persistence.ProjectQueryManager.getProject(ProjectQueryManager.java:240)
    at org.dependencytrack.persistence.QueryManager.getProject(QueryManager.java:369)
    at org.dependencytrack.resources.v1.ProjectResource.getProject(ProjectResource.java:146)
    at jdk.internal.reflect.GeneratedMethodAccessor145.invoke(Unknown Source)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
    at java.base/java.lang.reflect.Method.invoke(Unknown Source)
    at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:52)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:146)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:189)
    at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:176)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:93)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:478)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:400)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:81)
    at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:256)
    at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248)
    at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:292)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:274)
    at org.glassfish.jersey.internal.Errors.process(Errors.java:244)
    at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:265)
    at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:235)
    at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:684)
    at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:394)
    at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:346)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:358)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:311)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:205)
    at org.eclipse.jetty.servlet.ServletHolder$NotAsync.service(ServletHolder.java:1419)
    at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:764)
    at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1665)
    at alpine.server.filters.ContentSecurityPolicyFilter.doFilter(ContentSecurityPolicyFilter.java:225)
    at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:202)
    at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1635)
    at alpine.server.filters.ClickjackingFilter.doFilter(ClickjackingFilter.java:93)
    at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:202)
    at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1635)
    at alpine.server.filters.WhitelistUrlFilter.doFilter(WhitelistUrlFilter.java:166)
    at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:210)
    at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1635)
    at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:527)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:131)
    at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:578)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:223)
    at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1570)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:221)
    at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1385)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:176)
    at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:484)
    at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1543)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:174)
    at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1307)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:129)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
    at org.eclipse.jetty.server.Server.handle(Server.java:563)
    at org.eclipse.jetty.server.HttpChannel.lambda$handle$0(HttpChannel.java:505)
    at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:762)
    at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:497)
    at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:282)
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:314)
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100)
    at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
    at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.runTask(AdaptiveExecutionStrategy.java:416)
    at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.consumeTask(AdaptiveExecutionStrategy.java:385)
    at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.tryProduce(AdaptiveExecutionStrategy.java:272)
    at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.lambda$new$0(AdaptiveExecutionStrategy.java:140)
    at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:411)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:936)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1080)
    at java.base/java.lang.Thread.run(Unknown Source)
Caused by: org.postgresql.util.PSQLException: No value specified for parameter 3.
    at org.postgresql.core.v3.SimpleParameterList.checkAllParametersSet(SimpleParameterList.java:284)
    at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:352)
    at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:498)
    at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:415)
    at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:190)
    at org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:134)
    at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeQuery(ProxyPreparedStatement.java:52)
    at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeQuery(HikariProxyPreparedStatement.java)
    at org.datanucleus.store.rdbms.SQLController.executeStatementQuery(SQLController.java:548)
    at org.datanucleus.store.rdbms.query.JDOQLQuery.performExecute(JDOQLQuery.java:717)
    at org.datanucleus.store.query.Query.executeQuery(Query.java:2004)
    at org.datanucleus.store.query.Query.executeWithMap(Query.java:1911)
    at org.datanucleus.api.jdo.JDOQuery.executeInternal(JDOQuery.java:437)
    ... 72 common frames omitted
As a workaround, 
I have restarted DT API-Server and things have started working fine again.
Now the lookup api returns back expected results after restarting.
mphilipps commented 5 months ago

I looks I'm also encountering this issue in 4.10.1

Jenkins using the dependency-Track plugin tries to push a new BOM in the post build action, which fails with a 500.

docker log for the api container reports this:

2024-04-23 13:00:49,324 ERROR [GlobalExceptionHandler] Uncaught internal server error                                                                                                                                                                                                                                       
javax.jdo.JDODataStoreException: Iteration request failed : SELECT 'alpine.model.Team' AS "DN_TYPE","A1"."ID","A1"."NAME" AS "NUCORDER0","A1"."UUID","A0"."APIKEY_ID" FROM "APIKEYS_TEAMS" "A0" INNER JOIN "TEAM" "A1" ON "A0"."TEAM_ID" = "A1"."ID" WHERE EXISTS (SELECT 'alpine.model.ApiKey' AS "DN_TYPE","A0_SUB"."ID" A
S "DN_APPID" FROM "APIKEY" "A0_SUB" WHERE "A0_SUB"."APIKEY" = ? AND "A0"."APIKEY_ID" = "A0_SUB"."ID") ORDER BY "NUCORDER0"'alpine.model.Team' AS "DN_TYPE","A1"."ID","A1"."NAME" AS "NUCORDER0","A1"."UUID","A0"."APIKEY_ID","A1"."NAME" AS "NUCORDER0" FROM "APIKEYS_TEAMS" "A0" INNER JOIN "TEAM" "A1" ON "A0"."TEAM_ID" =
 "A1"."ID" WHERE EXISTS (SELECT 'alpine.model.ApiKey' AS "DN_TYPE","A0_SUB"."ID" AS "DN_APPID" FROM "APIKEY" "A0_SUB" WHERE "A0_SUB"."APIKEY" = ? AND "A0"."APIKEY_ID" = "A0_SUB"."ID") ORDER BY "NUCORDER0"                                                                                                                
        at org.datanucleus.api.jdo.JDOAdapter.getJDOExceptionForNucleusException(JDOAdapter.java:605)                                                                                                                                                                                                                       
        at org.datanucleus.api.jdo.JDOQuery.executeInternal(JDOQuery.java:456)                                                                                                                                                                                                                                              
        at org.datanucleus.api.jdo.JDOQuery.execute(JDOQuery.java:276)                                                                                                                                                                                                                                                      
        at alpine.persistence.AlpineQueryManager.getApiKey(AlpineQueryManager.java:102)                                                                                                                                                                                                                                     
        at alpine.server.auth.ApiKeyAuthenticationService.authenticate(ApiKeyAuthenticationService.java:67)                                                                                                                                                                                                                 
        at alpine.server.filters.AuthenticationFilter.filter(AuthenticationFilter.java:68)                                                                                                                                                                                                                                  
        at org.glassfish.jersey.server.ContainerFilteringStage.apply(ContainerFilteringStage.java:108)                                                                                                                                                                                                                      
        at org.glassfish.jersey.server.ContainerFilteringStage.apply(ContainerFilteringStage.java:44)                                                                                                                                                                                                                       
        at org.glassfish.jersey.process.internal.Stages.process(Stages.java:173)                                                                                                                                                                                                                                            
        at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:248)                                                                                                                                                                                                                                          
        at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248)                                                                                                                                                                                                                                                     
        at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244)                                                                                                                                                                                                                                                     
        at org.glassfish.jersey.internal.Errors.process(Errors.java:292)                                                                                                                                                                                                                                                    
        at org.glassfish.jersey.internal.Errors.process(Errors.java:274)                                                                                                                                                                                                                                                    
        at org.glassfish.jersey.internal.Errors.process(Errors.java:244)                                                                                                                                                                                                                                                    
        at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:265)                                                                                                                                                                                                                             
        at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:235)                                                                                                                                                                                                                                        
        at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:684)                                                                                                                                                                                                                               
        at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:394)                                                                                                                                                                                                                                     
        at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:346)                                                                                                                                                                                                                                         
        at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:358)                                                                                                                                                                                                                                 
        at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:311)                                                                                                                                                                                                                                 
        at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:205)                                                                                                                                                                                                                                 
        at org.eclipse.jetty.servlet.ServletHolder$NotAsync.service(ServletHolder.java:1419)                                                                                                                                                                                                                                
        at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:764)                                                                                                                                                                                                                                           
        at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1665)                                                                                                                                                                                                                             
        at alpine.server.filters.ContentSecurityPolicyFilter.doFilter(ContentSecurityPolicyFilter.java:225)                                                                                                                                                                                                                 
        at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:202)                                                                                                                                                                                                                                           
        at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1635)                                                                                                                                                                                                                                
        at alpine.server.filters.ClickjackingFilter.doFilter(ClickjackingFilter.java:93)
        at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:202)
        at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1635)
        at alpine.server.filters.WhitelistUrlFilter.doFilter(WhitelistUrlFilter.java:166)
        at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:210)
        at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1635)
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:527)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:131)
        at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:598)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:223)
        at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1570)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:221)
        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1384)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:176)
        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:484)
        at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1543)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:174)
        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1306)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:129)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
        at org.eclipse.jetty.server.Server.handle(Server.java:563)
        at org.eclipse.jetty.server.HttpChannel$RequestDispatchable.dispatch(HttpChannel.java:1598)
        at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:753)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:501)
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:287)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:314)
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100)
        at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.runTask(AdaptiveExecutionStrategy.java:421)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.consumeTask(AdaptiveExecutionStrategy.java:390)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.tryProduce(AdaptiveExecutionStrategy.java:277)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.run(AdaptiveExecutionStrategy.java:199)
        at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:411)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:969)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.doRunJob(QueuedThreadPool.java:1194)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1149)
        at java.base/java.lang.Thread.run(Unknown Source)
Caused by: org.postgresql.util.PSQLException: No value specified for parameter 2.
        at org.postgresql.core.v3.SimpleParameterList.checkAllParametersSet(SimpleParameterList.java:284)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:352)
        at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:498)
        at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:415)
        at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:190)
        at org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:134)
        at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeQuery(ProxyPreparedStatement.java:52)
        at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeQuery(HikariProxyPreparedStatement.java)
        at org.datanucleus.store.rdbms.SQLController.executeStatementQuery(SQLController.java:548)
        at org.datanucleus.store.rdbms.query.JDOQLQuery.performExecute(JDOQLQuery.java:717)
        at org.datanucleus.store.query.Query.executeQuery(Query.java:2004)
        at org.datanucleus.store.query.Query.executeWithArray(Query.java:1893)
        at org.datanucleus.api.jdo.JDOQuery.executeInternal(JDOQuery.java:433)
        ... 65 common frames omitted

Docker was recently updated from 5:26.0.2-1~debian.11~bullseye to 5:26.1.0-1~debian.11~bullseye.

After running docker compose down && docker compose up -d dependency-track accepts new BOMs once again.

ShuP1 commented 4 months ago

Solved on our side by removing the index directory and restarting the app

No idea of the root cause tho. The server just broke by itself during the weekend

akos-balla commented 3 weeks ago

We're getting something similar in the error logs when a user tries to expand a project which contains child projects:

2024-09-11 09:19:36,768 ERROR [GlobalExceptionHandler] Uncaught internal server error
javax.jdo.JDODataStoreException: Iteration request failed : SELECT 'org.dependencytrack.model.Tag''org.dependencytrack.model.Tag' AS "DN_TYPE", AS "DN_TYPE","A1"."ID","A1"."NAME" AS "NUCORDER0","A0"."PROJECT_ID","A1"."NAME" AS "NUCORDER0" FROM "PROJECTS_TAGS" "A0" INNER JOIN "TAG" "A1" ON "A0"."TAG_ID" = "A1"."ID" WHERE EXISTS (SELECT 'org.dependencytrack.model.Project' AS "DN_TYPE","A0_SUB"."ID" AS "DN_APPID" FROM "PROJECT" "A0_SUB" WHERE "A0_SUB"."UUID" = ? AND "A0"."PROJECT_ID" =                         "A0_SUB"."ID") ORDER BY "NUCORDER0"
        at org.datanucleus.api.jdo.JDOAdapter.getJDOExceptionForNucleusException(JDOAdapter.java:605)
        at org.datanucleus.api.jdo.JDOQuery.executeInternal(JDOQuery.java:456)
        at org.datanucleus.api.jdo.JDOQuery.execute(JDOQuery.java:276)
        at alpine.persistence.AbstractAlpineQueryManager.getObjectByUuid(AbstractAlpineQueryManager.java:549)
        at alpine.persistence.AbstractAlpineQueryManager.getObjectByUuid(AbstractAlpineQueryManager.java:563)
        at org.dependencytrack.resources.v1.FindingResource.getFindingsByProject(FindingResource.java:107)
        at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(Unknown Source)
        at java.base/java.lang.reflect.Method.invoke(Unknown Source)
        at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:52)
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:146)
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:189)
        at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:176)
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:93)
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:478)
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:400)
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:81)
        at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:256)
        at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248)
        at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244)
        at org.glassfish.jersey.internal.Errors.process(Errors.java:292)
        at org.glassfish.jersey.internal.Errors.process(Errors.java:274)
        at org.glassfish.jersey.internal.Errors.process(Errors.java:244)
        at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:265)
        at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:235)
        at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:684)
        at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:394)
        at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:346)
        at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:358)
        at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:311)
        at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:205)
        at org.eclipse.jetty.servlet.ServletHolder$NotAsync.service(ServletHolder.java:1419)
        at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:764)
        at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1665)
        at alpine.server.filters.ContentSecurityPolicyFilter.doFilter(ContentSecurityPolicyFilter.java:225)
        at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:202)
        at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1635)
        at alpine.server.filters.ClickjackingFilter.doFilter(ClickjackingFilter.java:93)
        at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:202)
        at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1635)
        at alpine.server.filters.WhitelistUrlFilter.doFilter(WhitelistUrlFilter.java:166)
        at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:210)
        at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1635)
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:527)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:131)
        at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:598)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:223)
        at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1570)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:221)
        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1384)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:176)
        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:484)
        at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1543)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:174)
        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1306)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:129)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
        at org.eclipse.jetty.server.Server.handle(Server.java:563)
        at org.eclipse.jetty.server.HttpChannel$RequestDispatchable.dispatch(HttpChannel.java:1598)
        at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:753)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:501)
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:287)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:314)
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100)
        at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.runTask(AdaptiveExecutionStrategy.java:421)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.consumeTask(AdaptiveExecutionStrategy.java:390)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.tryProduce(AdaptiveExecutionStrategy.java:277)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.run(AdaptiveExecutionStrategy.java:199)
        at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:411)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:969)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.doRunJob(QueuedThreadPool.java:1194)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1149)
        at java.base/java.lang.Thread.run(Unknown Source)
Caused by: org.postgresql.util.PSQLException: ERROR: syntax error at or near "AS"
  Position: 85
        at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2725)
        at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2412)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:371)
        at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:502)
        at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:419)
        at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:194)
        at org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:137)
        at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeQuery(ProxyPreparedStatement.java:52)
        at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeQuery(HikariProxyPreparedStatement.java)
        at org.datanucleus.store.rdbms.SQLController.executeStatementQuery(SQLController.java:584)
        at org.datanucleus.store.rdbms.query.JDOQLQuery.performExecute(JDOQLQuery.java:717)
        at org.datanucleus.store.query.Query.executeQuery(Query.java:2004)
        at org.datanucleus.store.query.Query.executeWithArray(Query.java:1893)
        at org.datanucleus.api.jdo.JDOQuery.executeInternal(JDOQuery.java:433)
        ... 72 common frames omitted

Deleting the k8s pod helps, but the issue re-appears randomly

nscuro commented 3 weeks ago

I think the root cause is the same as for https://github.com/DependencyTrack/dependency-track/issues/2061 (underlying issue here: https://github.com/datanucleus/datanucleus-rdbms/issues/491).

So this should be fixed in v4.12.

nscuro commented 3 weeks ago

Closing this as fixed for v4.12. The example error logs shared here all show the same symptom of partial or incorrectly assembled SQL queries, which matches the behavior described in https://github.com/datanucleus/datanucleus-rdbms/issues/491.

Please open a new issue if these errors persist post v4.12 upgrade.