search

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.66k stars 571 forks source link

DependencyTrack hangs when uploading a large SBOM to a project a second time #1905

Closed JayAtFujifilm closed 8 months ago

JayAtFujifilm commented 2 years ago

Current Behavior:

When we create a new project and upload a large SBOM (~7.5MB) there is no problem. However, if we then upload the SBOM again to the same project, the DepTrack API server hangs and never finishes processing. Inspection of the logfile via Docker indicates a stack overflow error (java.lang.StackOverflowError), as shown in the attached logfile (DependencyTrackLog.txt).

This happens even if we wait a long time (several days) to upload the second SBOM.

For smaller SBOMs we never have this problem.

Steps to Reproduce:

Using the DependencyTrack API:

  1. Create a new project
  2. Upload a large SBOM (~7.5MB)
  3. Verify that processing completes and the analysis is shown in the DepTrack UI.
  4. Upload the SBOM once again to the previously created project.
  5. DepTrack never finishes processing.

Expected Behavior:

Should be able to upload even large SBOMs multiple times to the same project.

Environment:

Additional Details:

Unfortunately, we cannot send you the actual SBOM for proprietary reasons.

nscuro commented 2 years ago

Wow, that's certainly a first. Ever seen anything like this happening before, @stevespringett?

2022-08-08 11:20:15,312 ERROR [LoggableUncaughtExceptionHandler] An unknown error occurred in an asynchronous event or notification thread
java.lang.StackOverflowError: null
    at java.base/java.security.AccessController.doPrivileged(Native Method)
    at org.datanucleus.state.StateManagerImpl.replaceStateManager(StateManagerImpl.java:2096)
    at org.datanucleus.state.StateManagerImpl.initialiseForDetached(StateManagerImpl.java:644)
    at org.datanucleus.state.StateManagerImpl.initialiseForDetached(StateManagerImpl.java:126)
    at org.datanucleus.state.StateManagerImpl.detachCopy(StateManagerImpl.java:4932)
    at org.datanucleus.state.StateManagerImpl.detachCopy(StateManagerImpl.java:126)
    at org.datanucleus.ExecutionContextImpl.detachObjectCopy(ExecutionContextImpl.java:2741)
    at org.datanucleus.store.fieldmanager.DetachFieldManager.processPersistableCopy(DetachFieldManager.java:76)
    at org.datanucleus.store.fieldmanager.DetachFieldManager.processField(DetachFieldManager.java:154)
    at org.datanucleus.store.fieldmanager.DetachFieldManager.internalFetchObjectField(DetachFieldManager.java:121)
    at org.datanucleus.store.fieldmanager.AbstractFetchDepthFieldManager.fetchObjectField(AbstractFetchDepthFieldManager.java:105)
    at org.datanucleus.state.StateManagerImpl.replacingObjectField(StateManagerImpl.java:1995)
    at org.dependencytrack.model.Component.dnReplaceField(Component.java)
    at org.dependencytrack.model.Component.dnReplaceFields(Component.java)
    at org.datanucleus.state.StateManagerImpl.replaceFields(StateManagerImpl.java:4320)
    at org.datanucleus.state.StateManagerImpl.replaceFields(StateManagerImpl.java:4345)
    at org.datanucleus.state.StateManagerImpl.detachCopy(StateManagerImpl.java:4941)
    at org.datanucleus.state.StateManagerImpl.detachCopy(StateManagerImpl.java:126)
    at org.datanucleus.ExecutionContextImpl.detachObjectCopy(ExecutionContextImpl.java:2741)
    at org.datanucleus.api.jdo.JDOPersistenceManager.jdoDetachCopy(JDOPersistenceManager.java:1121)
    at org.datanucleus.api.jdo.JDOPersistenceManager.detachCopy(JDOPersistenceManager.java:1150)
    at org.dependencytrack.persistence.ComponentQueryManager.createComponent(ComponentQueryManager.java:321)
    at org.dependencytrack.persistence.QueryManager.createComponent(QueryManager.java:452)
    at org.dependencytrack.tasks.BomUploadProcessingTask.processComponent(BomUploadProcessingTask.java:171)
    at org.dependencytrack.tasks.BomUploadProcessingTask.processComponent(BomUploadProcessingTask.java:178)
    at org.dependencytrack.tasks.BomUploadProcessingTask.processComponent(BomUploadProcessingTask.java:178)
    at org.dependencytrack.tasks.BomUploadProcessingTask.processComponent(BomUploadProcessingTask.java:178)
    at org.dependencytrack.tasks.BomUploadProcessingTask.processComponent(BomUploadProcessingTask.java:178)
    at org.dependencytrack.tasks.BomUploadProcessingTask.processComponent(BomUploadProcessingTask.java:178)
    at org.dependencytrack.tasks.BomUploadProcessingTask.processComponent(BomUploadProcessingTask.java:178)
    at org.dependencytrack.tasks.BomUploadProcessingTask.processComponent(BomUploadProcessingTask.java:178)
    at org.dependencytrack.tasks.BomUploadProcessingTask.processComponent(BomUploadProcessingTask.java:178)
    at org.dependencytrack.tasks.BomUploadProcessingTask.processComponent(BomUploadProcessingTask.java:178)
    at org.dependencytrack.tasks.BomUploadProcessingTask.processComponent(BomUploadProcessingTask.java:178)

@JayAtFujifilm, would it be possible to provide the SBOM to us so we can try to reproduce the issue?

stevespringett commented 2 years ago

7.5MB isn't that large. The BOM I use to perform all my performance testing with is 22MB and contains just over 9K components. See attached Bloated BOMs.zip.

I think there's something else going on here, either memory or host configuration, or perhaps something in the BOM itself that contains an unexpected large amount of data in a field.

syalioune commented 2 years ago

Hello Guys,

Looking at the code at line BomUploadProcessingTask.java:178 below, it is most likely a recursion issue (consistent with the stackoverflow error) due to a deep parent-child component hierarchy :

private void processComponent(final QueryManager qm, final Bom bom, Component component,
                                  final List<Component> flattenedComponents) {
        component.setInternal(InternalComponentIdentificationUtil.isInternalComponent(component, qm));
        ....
        if (component.getChildren() != null) {
            for (final Component child : component.getChildren()) {
                processComponent(qm, bom, child, flattenedComponents); <-- Line #178
            }
        }
    }

Would be interesting to know the maximum parent child relation depth in the problematic SBOM. PS : Default stack size on OpenJDK 17 is 1024k which is already quite big.

syalioune commented 2 years ago

Yup, Just replicated with attached sbom with a depth of 14 recursive childs for component bcprov-jdk15on bom.txt. It's a bit strange but first upload went ok, the issue appear at second upload.

dependency-track-dtrack-apiserver-1  | 2022-08-23 21:02:17,219 ERROR [LoggableUncaughtExceptionHandler] An unknown error occurred in an asynchronous event or notification thread
dependency-track-dtrack-apiserver-1  | java.lang.StackOverflowError: null
dependency-track-dtrack-apiserver-1  |  at java.base/java.security.AccessController.doPrivileged(Native Method)
dependency-track-dtrack-apiserver-1  |  at
 org.datanucleus.state.StateManagerImpl.replaceStateManager(StateManagerImpl.java:2096)
dependency-track-dtrack-apiserver-1  |  at org.datanucleus.state.StateManagerImpl.initialiseForDetached(StateManagerImpl.java:644)
dependency-track-dtrack-apiserver-1  |  at org.datanucleus.state.StateManagerImpl.initialiseForDetached(StateManagerImpl.java:126)
dependency-track-dtrack-apiserver-1  |  at org.datanucleus.state.StateManagerImpl.detachCopy(StateManagerImpl.java:4932)
dependency-track-dtrack-apiserver-1  |  at org.datanucleus.state.StateManagerImpl.detachCopy(StateManagerImpl.java:126)
dependency-track-dtrack-apiserver-1  |  at org.datanucleus.ExecutionContextImpl.detachObjectCopy(ExecutionContextImpl.java:2741)
dependency-track-dtrack-apiserver-1  |  at org.datanucleus.store.fieldmanager.DetachFieldManager.processPersistableCopy(DetachFieldManager.java:76)
dependency-track-dtrack-apiserver-1  |  at org.datanucleus.store.fieldmanager.DetachFieldManager.processField(DetachFieldManager.java:154)
dependency-track-dtrack-apiserver-1  |  at org.datanucleus.store.fieldmanager.DetachFieldManager.internalFetchObjectField(DetachFieldManager.java:121)
dependency-track-dtrack-apiserver-1  |  at org.datanucleus.store.fieldmanager.AbstractFetchDepthFieldManager.fetchObjectField(AbstractFetchDepthFieldManager.java:105)
dependency-track-dtrack-apiserver-1  |  at org.datanucleus.state.StateManagerImpl.replacingObjectField(StateManagerImpl.java:1995)
dependency-track-dtrack-apiserver-1  |  at org.dependencytrack.model.Component.dnReplaceField(Component.java)
dependency-track-dtrack-apiserver-1  |  at org.dependencytrack.model.Component.dnReplaceFields(Component.java)
dependency-track-dtrack-apiserver-1  |  at org.datanucleus.state.StateManagerImpl.replaceFields(StateManagerImpl.java:4320)
dependency-track-dtrack-apiserver-1  |  at org.datanucleus.state.StateManagerImpl.replaceFields(StateManagerImpl.java:4345)
dependency-track-dtrack-apiserver-1  |  at org.datanucleus.state.StateManagerImpl.detachCopy(StateManagerImpl.java:4941)
dependency-track-dtrack-apiserver-1  |  at org.datanucleus.state.StateManagerImpl.detachCopy(StateManagerImpl.java:126)
dependency-track-dtrack-apiserver-1  |  at org.datanucleus.ExecutionContextImpl.detachObjectCopy(ExecutionContextImpl.java:2741)
dependency-track-dtrack-apiserver-1  |  at org.datanucleus.api.jdo.JDOPersistenceManager.jdoDetachCopy(JDOPersistenceManager.java:1121)
dependency-track-dtrack-apiserver-1  |  at org.datanucleus.api.jdo.JDOPersistenceManager.detachCopy(JDOPersistenceManager.java:1150)
dependency-track-dtrack-apiserver-1  |  at org.dependencytrack.persistence.ComponentQueryManager.createComponent(ComponentQueryManager.java:321)
dependency-track-dtrack-apiserver-1  |  at org.dependencytrack.persistence.QueryManager.createComponent(QueryManager.java:452)
dependency-track-dtrack-apiserver-1  |  at org.dependencytrack.tasks.BomUploadProcessingTask.processComponent(BomUploadProcessingTask.java:171)
dependency-track-dtrack-apiserver-1  |  at org.dependencytrack.tasks.BomUploadProcessingTask.processComponent(BomUploadProcessingTask.java:178)
dependency-track-dtrack-apiserver-1  |  at org.dependencytrack.tasks.BomUploadProcessingTask.processComponent(BomUploadProcessingTask.java:178)
dependency-track-dtrack-apiserver-1  |  at org.dependencytrack.tasks.BomUploadProcessingTask.processComponent(BomUploadProcessingTask.java:178)
dependency-track-dtrack-apiserver-1  |  at org.dependencytrack.tasks.BomUploadProcessingTask.processComponent(BomUploadProcessingTask.java:178)
dependency-track-dtrack-apiserver-1  |  at org.dependencytrack.tasks.BomUploadProcessingTask.processComponent(BomUploadProcessingTask.java:178)
dependency-track-dtrack-apiserver-1  |  at org.dependencytrack.tasks.BomUploadProcessingTask.processComponent(BomUploadProcessingTask.java:178)
dependency-track-dtrack-apiserver-1  |  at org.dependencytrack.tasks.BomUploadProcessingTask.processComponent(BomUploadProcessingTask.java:178)
dependency-track-dtrack-apiserver-1  |  at org.dependencytrack.tasks.BomUploadProcessingTask.processComponent(BomUploadProcessingTask.java:178)
dependency-track-dtrack-apiserver-1  |  at org.dependencytrack.tasks.BomUploadProcessingTask.processComponent(BomUploadProcessingTask.java:178)
dependency-track-dtrack-apiserver-1  |  at org.dependencytrack.tasks.BomUploadProcessingTask.processComponent(BomUploadProcessingTask.java:178)
JayAtFujifilm commented 2 years ago

The SBOM for which this occurs contains a deeply nested component hierarchy that mimics the layout of our source code. To build the SBOM, we iterate through our source code, building an individual SBOM for each project (.Net or NodeJS), and use the Cyclone CLI tool to merge the individual SBOMs. We also use "pseudo-components" to represent source code folders that don't directly contain a project.

stevespringett commented 2 years ago

Thanks for the update. FYI, at this time, Dependency-Track will flatten the component inventory and will not preserve hierarchy. Support for parent/child relationships for both projects and components is planned.

JayAtFujifilm commented 2 years ago

Thank you, syalioune, for reproducing this so quickly!

syalioune commented 2 years ago

It would definitively help if you could provide your anonymized SBOM. My test SBOM is somewhat biased and extreme as I have duplicated the same component in the nested hierarchy probably causing an infinite recursion. I tested again with the attached sbom (14 nested different components) bom-2.txt and everything run smoothly. Nevertheless the algorithm could be improved to take that case into account.

JayAtFujifilm commented 2 years ago

We are working on trying to narrow down the cause the problem, and hope to have a smaller SBOM available for debugging soon.

sahil3112 commented 1 year ago

Hi @syalioune ,

Can you please mention what information is required in anonymized,

The same issue is still in latest version

Will the Structure of SBOM help to debug?

syalioune commented 1 year ago

What is important for reproduction will be to have :

sahil3112 commented 1 year ago

Here is the SBOM structure, I have verified that we can reproduce the issue by using the structure SBOM

sbom.txt

dancundy commented 1 year ago

Hi all,

We are also seeing this issue in our organisation. It sounds like this only happens on the second iteration. So would a feasible work around be to purge the database prior to each run?

What would be your recommendation?

Also happy to provide logs etc if that's going to help in anyway.

dancundy commented 1 year ago

@JayAtFujifilm Did you find a work around for this? @stevespringett Could I politely ask if there is any update around this issue?

syalioune commented 1 year ago

Looking at the different logs and sbom provided, the common pattern that emerge is a nested duplicate component like in the SBOM below

{
    "bomFormat": "CycloneDX",
    "specVersion": "1.4",
    "version": 1,
    "metadata": {
        "timestamp": "2023-01-01T11:01:51Z",
        "tools": [
            {
                "vendor": "changeme",
                "name": "changeme",
                "version": "0.62.3"
            }
        ]
    },
    "components": [
        {
            "bom-ref": "pkg:pypi/pillow@9.3.0",
            "type": "library",
            "name": "Pillow",
            "version": "9.3.0",
            "cpe": "cpe:2.3:a:alex_clark_\\(pil_fork_author\\):python-Pillow:9.3.0:*:*:*:*:*:*:*",
            "purl": "pkg:pypi/Pillow@9.3.0",
            "components": [
                {
                    "bom-ref": "pkg:pypi/pillow@9.3.0?package-id=212c649613e17901",
                    "type": "library",
                    "name": "Pillow",
                    "version": "9.3.0",
                    "cpe": "cpe:2.3:a:alex_clark_\\(pil_fork_author\\):python-Pillow:9.3.0:*:*:*:*:*:*:*",
                    "purl": "pkg:pypi/Pillow@9.3.0"
                }
            ]
        }
    ]
}

The scenario is :

Kind of the same premises as in https://github.com/DependencyTrack/dependency-track/issues/2131#issuecomment-1346796281

The SBOM is flawed to begin with. @sahil3112 @dancundy @JayAtFujifilm can you please confirm that your non redacted SBOM match the pattern of the SBOM snippet above and which tool you used to generate it ?

However DT can self protect against it. Two possibilities :

  1. Detect the issue on first upload and fail the BOM upload
  2. Detect the issue and skip the nested duplicate

I've submited a draft PR with the second alternative.

ghost commented 1 year ago

@syalioune I'm facing the same issue, with a BOM generated by cyclonedx-gomod. I did some analysis with a local version of DT and minimised the 600KB BOM to just a few components still reproducing the issue (at the end of this post). A few things I noticed (more details below):

Below are some more details:

So apparently in the input BOM there is parent-child relationship between two components that essentially refer to the same package (and which I would expect to be deduplicated on the second import of the BOM).

After the first import, this is what we see in the components overview in the DT UI:

Component Version Group Package URL (PURL)
cloud.google.com/go/storage v1.13.0 pkg:golang/cloud.google.com/go/storage@v1.13.0?type=module&goos=darwin&goarch=amd64
cloud.google.com/go/storage v1.13.0 pkg:golang/cloud.google.com/go/storage@v1.13.0?type=package

And this is what we see in the H2 console after the first import:

SELECT ID, NAME, PARENT_COMPONENT_ID, PURL, PURLCOORDINATES FROM COMPONENT

ID NAME PARENT_COMPONENT_ID PURL PURLCOORDINATES
936 cloud.google.com/go/storage null pkg:golang/cloud.google.com/go/storage@v1.13.0?type=module&goos=darwin&goarch=amd64 pkg:golang/cloud.google.com/go/storage@v1.13.0
937 cloud.google.com/go/storage 936 pkg:golang/cloud.google.com/go/storage@v1.13.0?type=package pkg:golang/cloud.google.com/go/storage@v1.13.0

So we see that the second component refers to the first one as its parent, which is consistent with the BOM.

During the second import, in ModelConverter.convert, the parent component is retrieved using its component identity:

Field Component Identity Value
ObjectType "COMPONENT"
purl "pkg:golang/cloud.google.com/go/storage@v1.13.0?type=module&goos=darwin&goarch=amd64"
purlCoordinates "pkg:golang/cloud.google.com/go/storage@v1.13.0"
name "cloud.google.com/go/storage"
version "v1.13.0"

The component returned is the one with ID=936, as expected.

Next, the child is being retrieved from the database by its component identity:

Field Component Identity Value
ObjectType "COMPONENT"
purl "pkg:golang/cloud.google.com/go/storage@v1.13.0?type=package"
purlCoordinates "pkg:golang/cloud.google.com/go/storage@v1.13.0"
name "cloud.google.com/go/storage"
version "v1.13.0"

In this case, also the component with ID=136 is returned. Consequently, the ModelConverter will assign this component as a child of the previous one, which is the same, hence creating the cyclic reference: component.setChildren(components);

Looking at the H2 console, we can see that the cyclic reference has been persisted after the second import. Moreover, the child component does not have a parent anymore, and the PURL property of the parent was set to the value of the child:

SELECT ID, NAME, PARENT_COMPONENT_ID, PURL, PURLCOORDINATES FROM COMPONENT

ID NAME PARENT_COMPONENT_ID PURL PURLCOORDINATES
936 cloud.google.com/go/storage 936 pkg:golang/cloud.google.com/go/storage@v1.13.0?type=package pkg:golang/cloud.google.com/go/storage@v1.13.0
937 cloud.google.com/go/storage null pkg:golang/cloud.google.com/go/storage@v1.13.0?type=package pkg:golang/cloud.google.com/go/storage@v1.13.0

I cannot judge whether this storage retrieval/persistence behaviour is expected or not, maybe it's supposed to be like that as part of the deduplication? Anyway I hope this helps in isolating and resolving the issue.

Below is the reduced BOM that has the issue: 

{
    "$schema": "http://cyclonedx.org/schema/bom-1.4.schema.json",
    "bomFormat": "CycloneDX",
    "specVersion": "1.4",
    "version": 1,
    "metadata": {
        "timestamp": "2023-05-16T08:57:13+02:00",
        "tools": [
            {
                "vendor": "CycloneDX",
                "name": "cyclonedx-gomod",
                "version": "v1.4.0"  
            }  
        ],
        "component": {
            "bom-ref": "pkg:golang/go.foobar.com/localfull@v0.0.0-20230515095825-3c9a500d1e33?type=module",
            "type": "application",
            "name": "go.foobar.com/localfull",
            "version": "v0.0.0-20230515095825-3c9a500d1e33",
            "purl": "pkg:golang/go.foobar.com/localfull@v0.0.0-20230515095825-3c9a500d1e33?type=module\u0026goos=darwin\u0026goarch=amd64",
            "properties": [
            ],
            "components": [
            ]
          }
    },
    "components": [
          {
            "bom-ref": "pkg:golang/cloud.google.com/go/storage@v1.13.0?type=module",
            "type": "library",
            "name": "cloud.google.com/go/storage",
            "version": "v1.13.0",
            "scope": "required",
            "hashes": [
              {
                "alg": "SHA-256",
                "content": "6a63ef842388f8796da7aacfbbeeb661dc2122b8dffb7e0f29500be07c206309"
              }
            ],
            "purl": "pkg:golang/cloud.google.com/go/storage@v1.13.0?type=module\u0026goos=darwin\u0026goarch=amd64",
            "components": [
              {
                "type": "library",
                "name": "cloud.google.com/go/storage",
                "version": "v1.13.0",
                "purl": "pkg:golang/cloud.google.com/go/storage@v1.13.0?type=package"
              }
            ],
            "evidence": {
              "licenses": [
                {
                  "license": {
                    "id": "Apache-2.0"
                  }
                }
              ]
            }
          }   
    ],
    "dependencies": [
      {
        "ref": "pkg:golang/go.foobar.com/localfull@v0.0.0-20230515095825-3c9a500d1e33?type=module",
        "dependsOn": [
          "pkg:golang/cloud.google.com/go/storage@v1.13.0?type=module"
        ]
      }
    ]
}
syalioune commented 1 year ago

Hello @salfie

Thanks for your thorough investigation. It match with my observations and based on that, I can provide the attached real life reproductible example cyclonedx-gomod-issue-1905.zip.

Given the example application and SBOM generation with cyclonedx-gomod using

cyclonedx-gomod app -json -output acme-app.bom.json -licenses -packages .

We end up with the nested golang module/package components

{
      "bom-ref": "pkg:golang/cloud.google.com/go/storage@v1.30.1?type=module",
      "type": "library",
      "name": "cloud.google.com/go/storage",
      "version": "v1.30.1",
      "scope": "required",
      "hashes": [
        {
          "alg": "SHA-256",
          "content": "b8e74cc40b3c1c4c6a0659cbb674323f4624bdb883a5d1928462adc7a53fa0d3"
        }
      ],
      "purl": "pkg:golang/cloud.google.com/go/storage@v1.30.1?type=module\u0026goos=linux\u0026goarch=amd64",
      "components": [
        {
          "type": "library",
          "name": "cloud.google.com/go/storage",
          "version": "v1.30.1",
          "purl": "pkg:golang/cloud.google.com/go/storage@v1.30.1?type=package"
        }
      ]
}

The ComponentQueryManager.matchSingleIdentity match both the module and package components because of this predicate (purl != null && purl == :purl) || (purlCoordinates != null && purlCoordinates == :purlCoordinates) in the generated JDOQL here (purlCoordinates are equal whereas purl are different).

if both purl and purlCoordinates are not null, we should maybe just filter on purl which is more specific ? @nscuro WDYT ?

nscuro commented 1 year ago

@syalioune Apologies for the delayed response, I only now got some time to look at BOM processing more closely.

if both purl and purlCoordinates are not null, we should maybe just filter on purl which is more specific ?

Agreed. I'd even go one step further: If purl is null, then also query for purl == null.

There are multiple issues closely related to this one. It all comes down to matchSingleIdentity being too lax, see my comment here: https://github.com/DependencyTrack/dependency-track/issues/2519#issuecomment-1621889555

For a change in Hyades, I now switched the matching logic to being "strict", and that fixes both #1905 and #2519: https://github.com/DependencyTrack/hyades-apiserver/pull/218/commits/641887986ec356a1baae7b31460d5cd11ea6bd5b#diff-3a9c95d09a4a5285037a7d5ba65613e09198ce2b460279622cadd8e703677d40

syalioune commented 1 year ago

Apologies for the delayed response, I only now got some time to look at BOM processing more closely.

No pb. Same time issues here.

I guess the fix you performed in hyades would be merged back here sometime ?

nscuro commented 1 year ago

I guess the fix you performed in hyades would be merged back here sometime ?

Yes, we have many improvements from Hyades in the pipeline that we want to contribute back soon, and this is of course one of them. 🤘

melba-lopez commented 1 year ago

@nscuro has this been addressed per #218? and would this be a 4.10 potential fix?

github-actions[bot] commented 7 months ago

This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.