DependencyTrack / DependencyTrack/dependency-track

BOM Upload failure [Object with id "org.dependencytrack.model.Component:123255" not found]

Open
#3,303 3 comments 0 reactions 0 assignees View on GitHub
defect p2 pending more information
Dominant language
Java
Stars
4.2k
Forks
811
Avg merge
8h 39m
Merged PRs (30d)
237

Description

### Current Behavior

Got several mails about upload failures of BOMs, checked the logs, found related to the affected 2 projects:

First I got these for both projects:
```
2023-12-14 09:09:20,550 [] INFO [org.dependencytrack.tasks.scanners.InternalAnalysisTask] Internal analysis complete
2023-12-14 09:09:20,565 [] INFO [org.dependencytrack.tasks.scanners.OssIndexAnalysisTask] Starting Sonatype OSS Index analysis task
2023-12-14 09:09:49,443 [] INFO [org.dependencytrack.tasks.BomUploadProcessingTask] Identified 0 new components
2023-12-14 09:09:49,443 [] INFO [org.dependencytrack.tasks.BomUploadProcessingTask] Processing CycloneDX dependency graph for project: 096f2fc4-be26-4c0a-b1f4-4c99018cd08b
2023-12-14 09:09:49,565 [] WARN [org.dependencytrack.persistence.ComponentQueryManager] Deletion of component failed because it didn't exist anymore.
2023-12-14 09:09:50,059 [] ERROR [org.dependencytrack.tasks.BomUploadProcessingTask] Error while processing bom
javax.jdo.JDOUserException: detachCopy cannot be called outside of a transaction when there are transient instances reachable.
at org.datanucleus.api.jdo.JDOAdapter.getJDOExceptionForNucleusException(JDOAdapter.java:698)
at org.datanucleus.api.jdo.JDOPersistenceManager.jdoDetachCopy(JDOPersistenceManager.java:1108)
at org.datanucleus.api.jdo.JDOPersistenceManager.detachCopyAll(JDOPersistenceManager.java:1180)
at alpine.persistence.AbstractAlpineQueryManager.detach(AbstractAlpineQueryManager.java:511)
at org.dependencytrack.tasks.BomUploadProcessingTask.inform(BomUploadProcessingTask.java:197)
at alpine.event.framework.BaseEventService.lambda$publish$0(BaseEventService.java:110)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.base/java.lang.Thread.run(Unknown Source)
Caused by: org.datanucleus.exceptions.NucleusUserException: detachCopy cannot be called outside of a transaction when there are transient instances reachable.
at org.datanucleus.ExecutionContextImpl.detachObjectCopy(ExecutionContextImpl.java:2647)
at org.datanucleus.api.jdo.JDOPersistenceManager.jdoDetachCopy(JDOPersistenceManager.java:1103)
... 7 common frames omitted
2023-12-14 09:09:59,015 [] INFO [org.dependencytrack.tasks.scanners.OssIndexAnalysisTask] Analyzing 128 component(s)
2023-12-14 09:10:04,339 [] INFO [org.dependencytrack.tasks.scanners.OssIndexAnalysisTask] Analyzing 128 component(s)
2023-12-14 09:10:05,878 [] INFO [org.dependencytrack.tasks.BomUploadProcessingTask] Identified 0 new components
2023-12-14 09:10:05,879 [] INFO [org.dependencytrack.tasks.BomUploadProcessingTask] Processing CycloneDX dependency graph for project: 4129a9dd-a6d0-4a1e-8517-4b0576780312
2023-12-14 09:10:06,089 [] WARN [org.dependencytrack.persistence.ComponentQueryManager] Deletion of component failed because it didn't exist anymore.
2023-12-14 09:10:06,726 [] ERROR [org.dependencytrack.tasks.BomUploadProcessingTask] Error while processing bom
javax.jdo.JDOUserException: detachCopy cannot be called outside of a transaction when there are transient instances reachable.
at org.datanucleus.api.jdo.JDOAdapter.getJDOExceptionForNucleusException(JDOAdapter.java:698)
at org.datanucleus.api.jdo.JDOPersistenceManager.jdoDetachCopy(JDOPersistenceManager.java:1108)
at org.datanucleus.api.jdo.JDOPersistenceManager.detachCopyAll(JDOPersistenceManager.java:1180)
at alpine.persistence.AbstractAlpineQueryManager.detach(AbstractAlpineQueryManager.java:511)
at org.dependencytrack.tasks.BomUploadProcessingTask.inform(BomUploadProcessingTask.java:197)
at alpine.event.framework.BaseEventService.lambda$publish$0(BaseEventService.java:110)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.base/java.lang.Thread.run(Unknown Source)
Caused by: org.datanucleus.exceptions.NucleusUserException: detachCopy cannot be called outside of a transaction when there are transient instances reachable.
at org.datanucleus.ExecutionContextImpl.detachObjectCopy(ExecutionContextImpl.java:2647)
at org.datanucleus.api.jdo.JDOPersistenceManager.jdoDetachCopy(JDOPersistenceManager.java:1103)
... 7 common frames omitted
```

Then I got these on both projects:
```
2023-12-14 09:11:29,882 [] ERROR [alpine.event.framework.LoggableUncaughtExceptionHandler] An unknown error occurred in an asynchronous event or notification thread
javax.jdo.JDOObjectNotFoundException: Object with id "org.dependencytrack.model.Component:123255" not found !
at org.datanucleus.api.jdo.JDOAdapter.getJDOExceptionForNucleusException(JDOAdapter.java:634)
at org.datanucleus.api.jdo.JDOPersistenceManager.getObjectById(JDOPersistenceManager.java:1726)
at alpine.persistence.AbstractAlpineQueryManager.getObjectById(AbstractAlpineQueryManager.java:535)
at org.dependencytrack.tasks.repositories.RepositoryMetaAnalyzerTask.inform(RepositoryMetaAnalyzerTask.java:91)
at alpine.event.framework.BaseEventService.lambda$publish$0(BaseEventService.java:110)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.base/java.lang.Thread.run(Unknown Source)
Caused by: org.datanucleus.exceptions.NucleusObjectNotFoundException: Object with id "org.dependencytrack.model.Component:123255" not found !
at org.datanucleus.store.rdbms.request.FetchRequest.execute(FetchRequest.java:473)
at org.datanucleus.store.rdbms.RDBMSPersistenceHandler.fetchObject(RDBMSPersistenceHandler.java:354)
at org.datanucleus.state.StateManagerImpl.loadFieldsFromDatastore(StateManagerImpl.java:1608)
at org.datanucleus.state.StateManagerImpl.validate(StateManagerImpl.java:5570)
at org.datanucleus.ExecutionContextImpl.findObject(ExecutionContextImpl.java:3446)
at org.datanucleus.ExecutionContextImpl.findObject(ExecutionContextImpl.java:2928)
at org.datanucleus.api.jdo.JDOPersistenceManager.getObjectById(JDOPersistenceManager.java:1721)
... 6 common frames omitted
```

Additionally, before both of above logs, I found following errors which may or may not be related (I somehow did not get an email about a failed BOM processing for these):

```
2023-12-14 08:14:31,486 [] INFO [org.dependencytrack.policy.PolicyEngine] Evaluating 267 component(s) against applicable policies
2023-12-14 08:14:34,510 [] INFO [org.dependencytrack.tasks.BomUploadProcessingTask] Identified 126 new components
2023-12-14 08:14:34,510 [] INFO [org.dependencytrack.tasks.BomUploadProcessingTask] Processing CycloneDX dependency graph for project: 096f2fc4-be26-4c0a-b1f4-4c99018cd08b
2023-12-14 08:14:36,063 [] INFO [org.dependencytrack.tasks.metrics.ProjectMetricsUpdateTask] Executing metrics update for project 22584923-e53f-4815-a8af-d68850b90fe9
2023-12-14 08:14:36,063 [] INFO [org.dependencytrack.tasks.metrics.ProjectMetricsUpdateTask] Executing metrics update for project abf25815-b054-4335-b053-11b612878d64
2023-12-14 08:14:36,064 [] INFO [org.dependencytrack.tasks.metrics.ProjectMetricsUpdateTask] Executing metrics update for project dc0da677-ec0c-46eb-85b0-345d65509187
2023-12-14 08:14:36,064 [] INFO [org.dependencytrack.tasks.metrics.ProjectMetricsUpdateTask] Executing metrics update for project 70b2dff0-cd4d-4bdd-87fa-0b129593f5ce
2023-12-14 08:14:36,064 [] INFO [org.dependencytrack.tasks.metrics.ProjectMetricsUpdateTask] Executing metrics update for project 6c3b8a36-7454-4a8a-934d-5e28a0c6258c
2023-12-14 08:14:36,064 [] INFO [org.dependencytrack.tasks.metrics.ProjectMetricsUpdateTask] Executing metrics update for project 2bc2aea5-77ec-47ad-8814-6a2b871a0728
2023-12-14 08:14:43,351 [] WARN [org.dependencytrack.tasks.repositories.NugetMetaAnalyzer] An error occurred while parsing upload time for a NuGet component - Repo returned: 1900-01-01T00:00:00+00:00
2023-12-14 08:14:43,351 [] WARN [org.dependencytrack.tasks.repositories.NugetMetaAnalyzer] An error occurred while parsing upload time for a NuGet component - Repo returned: 1900-01-01T00:00:00+00:00
2023-12-14 08:14:46,084 [] ERROR [org.dependencytrack.tasks.BomUploadProcessingTask] Error while processing bom
javax.jdo.JDOUserException: One or more instances could not be deleted
at org.datanucleus.api.jdo.JDOPersistenceManager.deletePersistentAll(JDOPersistenceManager.java:819)
at org.datanucleus.api.jdo.JDOPersistenceManager.deletePersistentAll(JDOPersistenceManager.java:798)
at alpine.persistence.AbstractAlpineQueryManager.delete(AbstractAlpineQueryManager.java:473)
at org.dependencytrack.persistence.ComponentQueryManager.recursivelyDelete(ComponentQueryManager.java:450)
at org.dependencytrack.persistence.ComponentQueryManager.reconcileComponents(ComponentQueryManager.java:585)
at org.dependencytrack.persistence.QueryManager.reconcileComponents(QueryManager.java:878)
at org.dependencytrack.tasks.BomUploadProcessingTask.inform(BomUploadProcessingTask.java:187)
at alpine.event.framework.BaseEventService.lambda$publish$0(BaseEventService.java:110)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.base/java.lang.Thread.run(Unknown Source)
Caused by: java.lang.NullPointerException: Cannot invoke "Object.hashCode()" because "" is null
at java.base/java.util.concurrent.ConcurrentHashMap.get(Unknown Source)
at org.datanucleus.ManagedRelationsHandler.getRelationshipManagerForStateManager(ManagedRelationsHandler.java:68)
at org.datanucleus.ExecutionContextImpl.getRelationshipManager(ExecutionContextImpl.java:3853)
at org.datanucleus.state.RelationshipManagerImpl.relationChange(RelationshipManagerImpl.java:182)
at org.datanucleus.store.rdbms.mapping.java.CollectionMapping.preDelete(CollectionMapping.java:301)
at org.datanucleus.store.rdbms.request.DeleteRequest.execute(DeleteRequest.java:213)
at org.datanucleus.store.rdbms.RDBMSPersistenceHandler.deleteObjectFromTable(RDBMSPersistenceHandler.java:534)
at org.datanucleus.store.rdbms.RDBMSPersistenceHandler.deleteObject(RDBMSPersistenceHandler.java:506)
at org.datanucleus.state.StateManagerImpl.internalDeletePersistent(StateManagerImpl.java:1260)
at org.datanucleus.state.StateManagerImpl.deletePersistent(StateManagerImpl.java:5513)
at org.datanucleus.ExecutionContextImpl.deleteObjectInternal(ExecutionContextImpl.java:2294)
at org.datanucleus.ExecutionContextImpl.deleteObjectWork(ExecutionContextImpl.java:2220)
at org.datanucleus.ExecutionContextImpl.deleteObjects(ExecutionContextImpl.java:2116)
at org.datanucleus.api.jdo.JDOPersistenceManager.deletePersistentAll(JDOPersistenceManager.java:814)
... 10 common frames omitted
2023-12-14 08:14:46,109 [] WARN [DataNucleus.General] ExecutionContext closed with active transaction, so rolling back the active transaction
```

```

2023-12-14 08:15:46,807 [] INFO [org.dependencytrack.policy.PolicyEngine] Evaluating 65 component(s) against applicable policies
2023-12-14 08:15:47,474 [] INFO [org.dependencytrack.tasks.scanners.InternalAnalysisTask] Internal analysis complete
2023-12-14 08:15:47,491 [] ERROR [org.dependencytrack.tasks.BomUploadProcessingTask] Error while processing bom
javax.jdo.JDOUserException: One or more instances could not be deleted
at org.datanucleus.api.jdo.JDOPersistenceManager.deletePersistentAll(JDOPersistenceManager.java:819)
at org.datanucleus.api.jdo.JDOPersistenceManager.deletePersistentAll(JDOPersistenceManager.java:798)
at alpine.persistence.AbstractAlpineQueryManager.delete(AbstractAlpineQueryManager.java:473)
at org.dependencytrack.persistence.ComponentQueryManager.recursivelyDelete(ComponentQueryManager.java:450)
at org.dependencytrack.persistence.ComponentQueryManager.reconcileComponents(ComponentQueryManager.java:585)
at org.dependencytrack.persistence.QueryManager.reconcileComponents(QueryManager.java:878)
at org.dependencytrack.tasks.BomUploadProcessingTask.inform(BomUploadProcessingTask.java:187)
at alpine.event.framework.BaseEventService.lambda$publish$0(BaseEventService.java:110)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.base/java.lang.Thread.run(Unknown Source)
Caused by: java.lang.NullPointerException: Cannot invoke "Object.hashCode()" because "" is null
at java.base/java.util.concurrent.ConcurrentHashMap.get(Unknown Source)
at org.datanucleus.ManagedRelationsHandler.getRelationshipManagerForStateManager(ManagedRelationsHandler.java:68)
at org.datanucleus.ExecutionContextImpl.getRelationshipManager(ExecutionContextImpl.java:3853)
at org.datanucleus.state.RelationshipManagerImpl.relationChange(RelationshipManagerImpl.java:182)
at org.datanucleus.store.rdbms.mapping.java.CollectionMapping.preDelete(CollectionMapping.java:301)
at org.datanucleus.store.rdbms.request.DeleteRequest.execute(DeleteRequest.java:213)
at org.datanucleus.store.rdbms.RDBMSPersistenceHandler.deleteObjectFromTable(RDBMSPersistenceHandler.java:534)
at org.datanucleus.store.rdbms.RDBMSPersistenceHandler.deleteObject(RDBMSPersistenceHandler.java:506)
at org.datanucleus.state.StateManagerImpl.internalDeletePersistent(StateManagerImpl.java:1260)
at org.datanucleus.state.StateManagerImpl.deletePersistent(StateManagerImpl.java:5513)
at org.datanucleus.ExecutionContextImpl.deleteObjectInternal(ExecutionContextImpl.java:2294)
at org.datanucleus.ExecutionContextImpl.deleteObjectWork(ExecutionContextImpl.java:2220)
at org.datanucleus.ExecutionContextImpl.deleteObjects(ExecutionContextImpl.java:2116)
at org.datanucleus.api.jdo.JDOPersistenceManager.deletePersistentAll(JDOPersistenceManager.java:814)
... 10 common frames omitted
```

### Steps to Reproduce

I don't know :(

Only thing I know is, that the project is likely one of the biggest we track (~1500 components) and that the versions are not newly created but BOM is uploaded into existing versions updating it.

### Expected Behavior

No errors or, if BOM is invalid, a message that the BOM is faulty.

### Dependency-Track Version

4.10.0

### Dependency-Track Distribution

Container Image

### Database Server

Microsoft SQL Server

### Database Server Version

_No response_

### Browser

Google Chrome

### Checklist

- [X] I have read and understand the [contributing guidelines](https://github.com/DependencyTrack/dependency-track/blob/master/CONTRIBUTING.md#filing-issues)
- [X] I have checked the [existing issues](https://github.com/DependencyTrack/dependency-track/issues) for whether this defect was already reported

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.