Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Refactor BOM upload processing for better efficiency, correctness, and consistency #3357

Merged
merged 22 commits into from
Feb 24, 2024

Conversation

nscuro
Copy link
Member

@nscuro nscuro commented Jan 7, 2024

Description

Note

This PR is largely a backport of DependencyTrack/hyades-apiserver#218 and later enhancements in hyades-apiserver. Huge thanks to @malice00, @mehab, @sahibamittal, and @VithikaS, who also contributed to this work.

Notable Changes

  • BOM processing is atomic
    • No partial state is left behind when processing fails midway
    • Less stress on the database due to fewer transactions
    • The search index is only updated when processing completed successfully, making inconsistencies less likely
  • BOM processing is faster and more efficient
    • De-duplication of components based on their identity now happens in-memory, before touching the database
    • In general fewer and less frequent database interactions
    • Smart usage of local caches to avoid redundant operations
    • Performance-oriented tuning of ORM features
    • Performing of database operations (UPDATEs, DELETEs) in batches where possible
      • Batching of INSERTs not possible due to ORM limitations
  • BOM processing has better observability
    • Emitted logs now include additional context, making it easier to correlate
    • Each log entry includes:
      • BOM format, spec version, serial number, version
      • Project UUID, name, version
    • In JSON format, the new context attributes are dedicated fields, making it trivial to be indexed by log aggregators such as ELK and Splunk

Addressed Issue

Fixes #1724
Fixes #1905
Fixes #2131
Fixes #2315
Fixes #2519
Fixes #2955 (Fixed by @malice00 via DependencyTrack/hyades-apiserver#278)
Fixes #3201
Fixes #3354
Fixes #3371

Relates to #3234

Additional Details

How to test

A container image including these changes has been published to:

dependencytrack/apiserver:3357-refactor-bom-processing

Here's an example docker-compose.yml for local testing:

services:
  apiserver:
    image: dependencytrack/apiserver:3357-refactor-bom-processing
    environment:
      # Set to "false" to switch back to previous implementation.
      BOM_PROCESSING_TASK_V2_ENABLED: "true"
    ports:
    - "127.0.0.1:8080:8080"
    volumes:
    - "apiserver-data:/data"
    restart: unless-stopped

  frontend:
    image: dependencytrack/frontend:snapshot
    environment:
      API_BASE_URL: "http://localhost:8080"
    ports:
    - "127.0.0.1:8081:8080"
    restart: unless-stopped

volumes:
  apiserver-data: { }

Checklist

  • I have read and understand the contributing guidelines
  • This PR fixes a defect, and I have provided tests to verify that the fix is effective
  • This PR implements an enhancement, and I have provided tests to verify that it works as intended
  • This PR introduces changes to the database model, and I have added corresponding update logic
  • This PR introduces new or alters existing behavior, and I have updated the documentation accordingly

`InternalComponentIdentificationUtil#isInternalComponent` previously executed two database queries, and up to two `Pattern#compile` calls, *for each invocation*.

The method is invoked for each component in a BOM (during BOM upload processing), or for *all* components in the portfolio (for `InternalComponentIdentificationTask`).

The work of querying and compiling is now performed only once, such that all following calls become much more efficient.

Signed-off-by: nscuro <nscuro@protonmail.com>
For BOMs with large dependency graphs, repeatedly iterating over all nodes when searching for a BOM ref becomes very expensive. Converting the graph into a `Map` structure allows for more efficient lookups.

It also helps with decoupling the processing a bit more from CycloneDX's object model.

Signed-off-by: nscuro <nscuro@protonmail.com>
The BOM processing logic relies on BOM refs being there, but not all BOM generators populate that field.

Signed-off-by: nscuro <nscuro@protonmail.com>
…leanup

Signed-off-by: nscuro <nscuro@protonmail.com>
Signed-off-by: nscuro <nscuro@protonmail.com>
Signed-off-by: nscuro <nscuro@protonmail.com>
…omponent`

Signed-off-by: nscuro <nscuro@protonmail.com>
Signed-off-by: nscuro <nscuro@protonmail.com>
Now surrounds MDC key-value pairs with brackets if any are present, and omits brackets when MDC is empty.

Signed-off-by: nscuro <nscuro@protonmail.com>
Signed-off-by: nscuro <nscuro@protonmail.com>
Signed-off-by: nscuro <nscuro@protonmail.com>
Signed-off-by: nscuro <nscuro@protonmail.com>
Signed-off-by: nscuro <nscuro@protonmail.com>
Signed-off-by: nscuro <nscuro@protonmail.com>
Signed-off-by: nscuro <nscuro@protonmail.com>
Signed-off-by: nscuro <nscuro@protonmail.com>
Signed-off-by: nscuro <nscuro@protonmail.com>
Signed-off-by: nscuro <nscuro@protonmail.com>
Signed-off-by: nscuro <nscuro@protonmail.com>
Received insufficient user feedback so far, so for 4.11 users will need to manually enable this.

Signed-off-by: nscuro <nscuro@protonmail.com>
@nscuro nscuro force-pushed the refactor-bom-upload-processing branch from 6dd9e54 to 7e21023 Compare January 28, 2024 21:58
Signed-off-by: nscuro <nscuro@protonmail.com>
@melba-lopez
Copy link
Contributor

melba-lopez commented Feb 3, 2024

  1. Created several projects
  2. Uploaded a v1.5 BOM that was 2.2MB (test1) --> note nuget error on timestamp
  3. Uploaded a malformed v1.4 BOM that was 9.1MB to test 2 project
  4. Uploaded a v1.5 BOM that was 6.9MB (test2)
  5. After last BOM upload, logs show jetty errors

**note the logs are showing a special character before the date/timestamp

Step 2

image

2024-02-03 14:48:28,619 INFO [BomUploadProcessingTaskV2] Consuming uploaded BOM [bomSerialNumber=810aab37-5b86-4e0d-83e8-03baa909305e, bomFormat=CycloneDX, bomUploadToken=7348b41c-6261-45fc-bac5-80150f6eaadd, projectName=test1, bomSpecVersion=1.5, projectUuid=0ca7bcd2-7af9-46d6-b325-4c4fbfa7a927, projectVersion=null, bomVersion=1]
�2024-02-03 14:48:28,760 INFO [BomUploadProcessingTaskV2] Consumed 2990 components (3005 before de-duplication), 0 services (0 before de-duplication), and 0 dependency graph entries [bomSerialNumber=810aab37-5b86-4e0d-83e8-03baa909305e, bomFormat=CycloneDX, bomUploadToken=7348b41c-6261-45fc-bac5-80150f6eaadd, projectName=test1, bomSpecVersion=1.5, projectUuid=0ca7bcd2-7af9-46d6-b325-4c4fbfa7a927, projectVersion=null, bomVersion=1]
2024-02-03 14:48:28,799 INFO [BomUploadProcessingTaskV2] Processing 2990 components [bomSerialNumber=810aab37-5b86-4e0d-83e8-03baa909305e, bomFormat=CycloneDX, bomUploadToken=7348b41c-6261-45fc-bac5-80150f6eaadd, projectName=test1, bomSpecVersion=1.5, projectUuid=0ca7bcd2-7af9-46d6-b325-4c4fbfa7a927, projectVersion=null, bomVersion=1]
2024-02-03 14:48:30,225 INFO [BomUploadProcessingTaskV2] Processing 0 services [bomSerialNumber=810aab37-5b86-4e0d-83e8-03baa909305e, bomFormat=CycloneDX, bomUploadToken=7348b41c-6261-45fc-bac5-80150f6eaadd, projectName=test1, bomSpecVersion=1.5, projectUuid=0ca7bcd2-7af9-46d6-b325-4c4fbfa7a927, projectVersion=null, bomVersion=1]
2024-02-03 14:48:30,226 INFO [BomUploadProcessingTaskV2] Processing 0 dependency graph entries [bomSerialNumber=810aab37-5b86-4e0d-83e8-03baa909305e, bomFormat=CycloneDX, bomUploadToken=7348b41c-6261-45fc-bac5-80150f6eaadd, projectName=test1, bomSpecVersion=1.5, projectUuid=0ca7bcd2-7af9-46d6-b325-4c4fbfa7a927, projectVersion=null, bomVersion=1]
2024-02-03 14:48:30,335 INFO [BomUploadProcessingTaskV2] BOM processed successfully in 00:00:02.027 [bomSerialNumber=810aab37-5b86-4e0d-83e8-03baa909305e, bomFormat=CycloneDX, bomUploadToken=7348b41c-6261-45fc-bac5-80150f6eaadd, projectName=test1, bomSpecVersion=1.5, projectUuid=0ca7bcd2-7af9-46d6-b325-4c4fbfa7a927, projectVersion=null, bomVersion=1]
�2024-02-03 14:48:30,360 INFO [RepositoryMetaAnalyzerTask] Performing component repository metadata analysis against 2990 components
2024-02-03 14:48:32,347 INFO [InternalAnalysisTask] Starting internal analysis task
2024-02-03 14:48:32,348 INFO [InternalAnalysisTask] Analyzing 109 component(s)
2024-02-03 14:48:32,499 INFO [InternalAnalysisTask] Internal analysis complete
�2024-02-03 14:48:32,505 WARN [OssIndexAnalysisTask] An API username or token has not been specified for use with OSS Index. Using anonymous access
2024-02-03 14:48:32,506 INFO [OssIndexAnalysisTask] Starting Sonatype OSS Index analysis task
2024-02-03 14:48:33,932 INFO [OssIndexAnalysisTask] Analyzing 109 component(s)
2024-02-03 14:48:33,932 INFO [OssIndexAnalysisTask] Sonatype OSS Index analysis complete
2024-02-03 14:48:33,953 INFO [PolicyEngine] Evaluating 2990 component(s) against applicable policies
�2024-02-03 14:48:34,979 WARN [NugetMetaAnalyzer] An error occurred while parsing upload time for a NuGet component - Repo returned: 1900-01-01T00:00:00+00:00
�2024-02-03 14:48:34,980 WARN [NugetMetaAnalyzer] An error occurred while parsing upload time for a NuGet component - Repo returned: 1900-01-01T00:00:00+00:00
�2024-02-03 14:48:36,356 INFO [RepositoryMetaAnalyzerTask] Completed component repository metadata analysis against 2990 components
2024-02-03 14:48:36,358 INFO [PolicyEngine] Evaluating 2990 component(s) against applicable policies
2024-02-03 14:48:40,326 INFO [PolicyEngine] Policy analysis complete
�2024-02-03 14:48:40,330 INFO [ProjectMetricsUpdateTask] Executing metrics update for project 0ca7bcd2-7af9-46d6-b325-4c4fbfa7a927
2024-02-03 14:48:43,080 INFO [PolicyEngine] Policy analysis complete
�2024-02-03 14:48:43,081 INFO [ProjectMetricsUpdateTask] Executing metrics update for project 0ca7bcd2-7af9-46d6-b325-4c4fbfa7a927

Step 3

2024-02-03 14:53:44,850 INFO [ProjectResource] Project test2 updated by admin
2024-02-03 14:55:52,067 INFO [BomUploadProcessingTaskV2] Consuming uploaded BOM [bomSerialNumber=b456d57b-0b19-48cc-a3cb-6c882c69d82d, bomFormat=CycloneDX, bomUploadToken=efa13e17-6e8c-40a2-ac62-5c1bba591e6f, projectName=test2, bomSpecVersion=1.4, projectUuid=231a05f3-f724-4fd6-a558-9b2181c37210, projectVersion=null, bomVersion=1]
�2024-02-03 14:55:52,218 INFO [BomUploadProcessingTaskV2] Consumed 13880 components (13880 before de-duplication), 0 services (0 before de-duplication), and 2663 dependency graph entries [bomSerialNumber=b456d57b-0b19-48cc-a3cb-6c882c69d82d, bomFormat=CycloneDX, bomUploadToken=efa13e17-6e8c-40a2-ac62-5c1bba591e6f, projectName=test2, bomSpecVersion=1.4, projectUuid=231a05f3-f724-4fd6-a558-9b2181c37210, projectVersion=null, bomVersion=1]
2024-02-03 14:55:52,222 INFO [BomUploadProcessingTaskV2] Processing 13880 components [bomSerialNumber=b456d57b-0b19-48cc-a3cb-6c882c69d82d, bomFormat=CycloneDX, bomUploadToken=efa13e17-6e8c-40a2-ac62-5c1bba591e6f, projectName=test2, bomSpecVersion=1.4, projectUuid=231a05f3-f724-4fd6-a558-9b2181c37210, projectVersion=null, bomVersion=1]
�2024-02-03 14:55:54,146 WARN [Persist] Insert of object "org.dependencytrack.model.Component@4b2ee8b1" using statement "INSERT INTO COMPONENT (AUTHOR,<redacted> CLASSIFIER,COPYRIGHT,CPE,DESCRIPTION,DIRECT_DEPENDENCIES,EXTENSION,EXTERNAL_REFERENCES,FILENAME,"GROUP",INTERNAL,LAST_RISKSCORE,LICENSE,LICENSE_EXPRESSION,LICENSE_URL,MD5,"NAME",TEXT,PARENT_COMPONENT_ID,PROJECT_ID,PUBLISHER,PURL,PURLCOORDINATES,LICENSE_ID,SHA1,SHA_256,SHA_384,SHA3_256,SHA3_384,SHA3_512,SHA_512,SUPPLIER,SWIDTAGID,UUID,VERSION) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)" failed : NULL not allowed for column "NAME"; SQL statement:
INSERT INTO COMPONENT (AUTHOR,<redacted>,CLASSIFIER,COPYRIGHT,CPE,DESCRIPTION,DIRECT_DEPENDENCIES,EXTENSION,EXTERNAL_REFERENCES,FILENAME,"GROUP",INTERNAL,LAST_RISKSCORE,LICENSE,LICENSE_EXPRESSION,LICENSE_URL,MD5,"NAME",TEXT,PARENT_COMPONENT_ID,PROJECT_ID,PUBLISHER,PURL,PURLCOORDINATES,LICENSE_ID,SHA1,SHA_256,SHA_384,SHA3_256,SHA3_384,SHA3_512,SHA_512,SUPPLIER,SWIDTAGID,UUID,VERSION) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?) [23502-224] [bomSerialNumber=b456d57b-0b19-48cc-a3cb-6c882c69d82d, bomFormat=CycloneDX, bomUploadToken=efa13e17-6e8c-40a2-ac62-5c1bba591e6f, projectName=test2, bomSpecVersion=1.4, projectUuid=231a05f3-f724-4fd6-a558-9b2181c37210, projectVersion=null, bomVersion=1]
�2024-02-03 14:55:54,182 ERROR [BomUploadProcessingTaskV2] Failed to process BOM [bomUploadToken=efa13e17-6e8c-40a2-ac62-5c1bba591e6f, projectName=test2, projectUuid=231a05f3-f724-4fd6-a558-9b2181c37210, projectVersion=null]

Step 4

image

2024-02-03 15:02:35,916 INFO [BomUploadProcessingTaskV2] Consuming uploaded BOM [bomSerialNumber=9bf73e90-4881-485f-8164-231cb610eda5, bomFormat=CycloneDX, bomUploadToken=5c066d28-5209-4e00-8958-2b9a390c12fe, projectName=test2, bomSpecVersion=1.5, projectUuid=231a05f3-f724-4fd6-a558-9b2181c37210, projectVersion=null, bomVersion=1]
�2024-02-03 15:02:35,993 INFO [BomUploadProcessingTaskV2] Consumed 5915 components (5919 before de-duplication), 0 services (0 before de-duplication), and 1 dependency graph entries [bomSerialNumber=9bf73e90-4881-485f-8164-231cb610eda5, bomFormat=CycloneDX, bomUploadToken=5c066d28-5209-4e00-8958-2b9a390c12fe, projectName=test2, bomSpecVersion=1.5, projectUuid=231a05f3-f724-4fd6-a558-9b2181c37210, projectVersion=null, bomVersion=1]
2024-02-03 15:02:35,997 INFO [BomUploadProcessingTaskV2] Processing 5915 components [bomSerialNumber=9bf73e90-4881-485f-8164-231cb610eda5, bomFormat=CycloneDX, bomUploadToken=5c066d28-5209-4e00-8958-2b9a390c12fe, projectName=test2, bomSpecVersion=1.5, projectUuid=231a05f3-f724-4fd6-a558-9b2181c37210, projectVersion=null, bomVersion=1]
2024-02-03 15:02:37,736 INFO [BomUploadProcessingTaskV2] Processing 0 services [bomSerialNumber=9bf73e90-4881-485f-8164-231cb610eda5, bomFormat=CycloneDX, bomUploadToken=5c066d28-5209-4e00-8958-2b9a390c12fe, projectName=test2, bomSpecVersion=1.5, projectUuid=231a05f3-f724-4fd6-a558-9b2181c37210, projectVersion=null, bomVersion=1]
2024-02-03 15:02:37,736 INFO [BomUploadProcessingTaskV2] Processing 1 dependency graph entries [bomSerialNumber=9bf73e90-4881-485f-8164-231cb610eda5, bomFormat=CycloneDX, bomUploadToken=5c066d28-5209-4e00-8958-2b9a390c12fe, projectName=test2, bomSpecVersion=1.5, projectUuid=231a05f3-f724-4fd6-a558-9b2181c37210, projectVersion=null, bomVersion=1]
2024-02-03 15:02:37,904 INFO [BomUploadProcessingTaskV2] BOM processed successfully in 00:00:02.099 [bomSerialNumber=9bf73e90-4881-485f-8164-231cb610eda5, bomFormat=CycloneDX, bomUploadToken=5c066d28-5209-4e00-8958-2b9a390c12fe, projectName=test2, bomSpecVersion=1.5, projectUuid=231a05f3-f724-4fd6-a558-9b2181c37210, projectVersion=null, bomVersion=1]
�2024-02-03 15:02:37,930 INFO [RepositoryMetaAnalyzerTask] Performing component repository metadata analysis against 5915 components
2024-02-03 15:02:39,752 INFO [InternalAnalysisTask] Starting internal analysis task
2024-02-03 15:02:39,752 INFO [InternalAnalysisTask] Analyzing 5913 component(s)
2024-02-03 15:02:44,889 INFO [InternalAnalysisTask] Internal analysis complete
�2024-02-03 15:02:44,891 WARN [OssIndexAnalysisTask] An API username or token has not been specified for use with OSS Index. Using anonymous access
2024-02-03 15:02:44,892 INFO [OssIndexAnalysisTask] Starting Sonatype OSS Index analysis task
2024-02-03 15:02:45,975 INFO [OssIndexAnalysisTask] Analyzing 128 component(s)
2024-02-03 15:02:46,620 INFO [OssIndexAnalysisTask] Analyzing 86 component(s)
2024-02-03 15:02:46,621 INFO [OssIndexAnalysisTask] Sonatype OSS Index analysis complete
2024-02-03 15:02:46,624 INFO [PolicyEngine] Evaluating 5915 component(s) against applicable policies
2024-02-03 15:02:56,166 INFO [PolicyEngine] Policy analysis complete
�2024-02-03 15:02:56,167 INFO [ProjectMetricsUpdateTask] Executing metrics update for project 231a05f3-f724-4fd6-a558-9b2181c37210
�2024-02-03 15:03:08,149 INFO [RepositoryMetaAnalyzerTask] Completed component repository metadata analysis against 5915 components
2024-02-03 15:03:08,153 INFO [PolicyEngine] Evaluating 5915 component(s) against applicable policies
2024-02-03 15:03:17,359 INFO [PolicyEngine] Policy analysis complete
�2024-02-03 15:03:17,360 INFO [ProjectMetricsUpdateTask] Executing metrics update for project 231a05f3-f724-4fd6-a558-9b2181c37210

Step 5

image image image

@nscuro
Copy link
Member Author

nscuro commented Feb 4, 2024

Thanks for the feedback @melba-lopez!


The Jetty error you've been seeing, I fixed some aspects in the frontend that could cause it:

Basically the frontend issued redundant requests, where some of them would be abandoned before the API server could send the full response. There may be more of those issues lurking in the frontend codebase that I wasn't able to spot yet.


In Step 3, the BOM processing failed because at least one component did not have a name:

NULL not allowed for column "NAME"

This is in line with the schema, where name is a required field: https://cyclonedx.org/docs/1.5/json/#components_items_name

As we touched on in Slack, the solution to that would be covered by #3218. Invalid BOMs should be rejected immediately.


For step 4, looks like the 6.9MB BOM was processed in just above 2sec, nice!

2024-02-03 15:02:37,904 INFO [BomUploadProcessingTaskV2] BOM processed successfully in 00:00:02.099

@melba-lopez
Copy link
Contributor

- Test 1 : Uploaded a 4.6 MB SBOM (v1.4)

Bom uploaded successfully

- Test 2: upload a malformed 9.8 MB SBOM (v1.4)

Note that the toast notification did give a "bom upload successful" even though no components show up and the "name" is not there. ---> per your comment above would be covered by #3218
image

2024-02-06 02:26:27,258 INFO [BomUploadProcessingTaskV2] Consuming uploaded BOM [bomSerialNumber=b456d57b-0b19-48cc-a3cb-6c882c69d82d, bomFormat=CycloneDX, bomUploadToken=93fc7d4b-dcbd-4d51-bc15-0fec3bb52c93, projectName=test 2, bomSpecVersion=1.4, projectUuid=7a12145c-66ab-427e-a8cf-3bf5cf0e64f6, projectVersion=null, bomVersion=1]
�2024-02-06 02:26:27,431 INFO [BomUploadProcessingTaskV2] Consumed 13880 components (13880 before de-duplication), 0 services (0 before de-duplication), and 2663 dependency graph entries [bomSerialNumber=b456d57b-0b19-48cc-a3cb-6c882c69d82d, bomFormat=CycloneDX, bomUploadToken=93fc7d4b-dcbd-4d51-bc15-0fec3bb52c93, projectName=test 2, bomSpecVersion=1.4, projectUuid=7a12145c-66ab-427e-a8cf-3bf5cf0e64f6, projectVersion=null, bomVersion=1]
2024-02-06 02:26:27,439 INFO [BomUploadProcessingTaskV2] Processing 13880 components [bomSerialNumber=b456d57b-0b19-48cc-a3cb-6c882c69d82d, bomFormat=CycloneDX, bomUploadToken=93fc7d4b-dcbd-4d51-bc15-0fec3bb52c93, projectName=test 2, bomSpecVersion=1.4, projectUuid=7a12145c-66ab-427e-a8cf-3bf5cf0e64f6, projectVersion=null, bomVersion=1]
�2024-02-06 02:26:28,276 WARN [Persist] Insert of object "org.dependencytrack.model.Component@7ad8adb" using statement "INSERT INTO COMPONENT (AUTHOR,,CLASSIFIER,COPYRIGHT,CPE,DESCRIPTION,DIRECT_DEPENDENCIES,EXTENSION,EXTERNAL_REFERENCES,FILENAME,"GROUP",INTERNAL,LAST_RISKSCORE,LICENSE,LICENSE_EXPRESSION,LICENSE_URL,MD5,"NAME",TEXT,PARENT_COMPONENT_ID,PROJECT_ID,PUBLISHER,PURL,PURLCOORDINATES,LICENSE_ID,SHA1,SHA_256,SHA_384,SHA3_256,SHA3_384,SHA3_512,SHA_512,SUPPLIER,SWIDTAGID,UUID,VERSION) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)" failed : NULL not allowed for column "NAME"; SQL statement:

Test 3: Upload an 8.8MB SBOM (v1.4)

2024-02-06 02:35:22,510 INFO [BomUploadProcessingTaskV2] BOM processed successfully in 00:00:05.119 [bomSerialNumber=092c8b15-d811-4843-9f46-a5dbacebd767, bomFormat=CycloneDX, bomUploadToken=3a411eac-c69c-4a43-a83f-a94ebab3fe87, projectName=test 2, bomSpecVersion=1.4, projectUuid=7a12145c-66ab-427e-a8cf-3bf5cf0e64f6, projectVersion=null, bomVersion=1]
�2024-02-06 02:35:22,546 INFO [RepositoryMetaAnalyzerTask] Performing component repository metadata analysis against 11133 components
2024-02-06 02:35:25,481 INFO [InternalAnalysisTask] Starting internal analysis task
2024-02-06 02:35:25,482 INFO [InternalAnalysisTask] Analyzing 10994 component(s)

Another interesting issue came up where a value for a CVE was not able to be stored into the DB because of the 255 character limit.

2024-02-06 02:35:49,626 ERROR [OssIndexAnalysisTask] Request failure
�javax.jdo.JDOFatalUserException: Attempt to store value "https://ossindex.sonatype.org/vulnerability/CVE-2023-47108?component-type=golang&component-`name=go.opentelemetry.io%2Fcontrib%2Finstrumentation%2Fgoogle.golang.org%2Fgrpc%2Fotelgrpc&utm_source=dependency-track&utm_medium=integration&utm_content=v4.11.0-SNAPSHOT" in column "REFERENCE_URL" that has maximum length of 255. Please correct your data!at org.datanucleus.api.jdo.JDOAdapter.getJDOExceptionForNucleusException(JDOAdapter.java:678) at org.datanucleus.api.jdo.JDOTransaction.commit(JDOTransaction.java:160) at alpine.persistence.AbstractAlpineQueryManager.persist(AbstractAlpineQueryManager.java:428) at org.dependencytrack.persistence.VulnerabilityQueryManager.addVulnerability(VulnerabilityQueryManager.java:218) at org.dependencytrack.persistence.QueryManager.addVulnerability(QueryManager.java:740) at org.dependencytrack.tasks.scanners.OssIndexAnalysisTask.processResults(OssIndexAnalysisTask.java:303) at org.dependencytrack.tasks.scanners.OssIndexAnalysisTask.analyze(OssIndexAnalysisTask.java:211) at org.dependencytrack.tasks.scanners.OssIndexAnalysisTask.inform(OssIndexAnalysisTask.java:152) at org.dependencytrack.tasks.VulnerabilityAnalysisTask.performAnalysis(VulnerabilityAnalysisTask.java:162) at org.dependencytrack.tasks.VulnerabilityAnalysisTask.analyzeComponents(VulnerabilityAnalysisTask.java:121) at org.dependencytrack.tasks.VulnerabilityAnalysisTask.inform(VulnerabilityAnalysisTask.java:70) 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:Attempt to store value "https://ossindex.sonatype.org/vulnerability/CVE-2023-47108?component-type=golang&component-name=go.opentelemetry.io%2Fcontrib%2Finstrumentation%2Fgoogle.golang.org%2Fgrpc%2Fotelgrpc&utm_source=dependency-track&utm_medium=integration&utm_content=v4.11.0-SNAPSHOT" in column "REFERENCE_URL" that has maximum length of 255. Please correct your data!`
at org.datanucleus.store.rdbms.mapping.column.CharColumnMapping.setString(CharColumnMapping.java:253)
at org.datanucleus.store.rdbms.mapping.java.SingleFieldMapping.setString(SingleFieldMapping.java:202)
at org.datanucleus.store.rdbms.fieldmanager.ParameterSetter.storeStringField(ParameterSetter.java:158)
at org.datanucleus.state.StateManagerImpl.providedStringField(StateManagerImpl.java:1903)
at org.dependencytrack.model.FindingAttribution.dnProvideField(FindingAttribution.java)
at org.dependencytrack.model.FindingAttribution.dnProvideFields(FindingAttribution.java)
at org.datanucleus.state.StateManagerImpl.provideFields(StateManagerImpl.java:2559)
at org.datanucleus.store.rdbms.request.InsertRequest.execute(InsertRequest.java:383)
at org.datanucleus.store.rdbms.RDBMSPersistenceHandler.insertObjectInTable(RDBMSPersistenceHandler.java:162)
at org.datanucleus.store.rdbms.RDBMSPersistenceHandler.insertObject(RDBMSPersistenceHandler.java:138)
at org.datanucleus.state.StateManagerImpl.internalMakePersistent(StateManagerImpl.java:4587)
at org.datanucleus.state.StateManagerImpl.flush(StateManagerImpl.java:5821)
at org.datanucleus.flush.FlushOrdered.execute(FlushOrdered.java:96)
at org.datanucleus.ExecutionContextImpl.flushInternal(ExecutionContextImpl.java:3956)
at org.datanucleus.ExecutionContextImpl.flush(ExecutionContextImpl.java:3902)
at org.datanucleus.ExecutionContextImpl.preCommit(ExecutionContextImpl.java:4073)
at org.datanucleus.ExecutionContextImpl.transactionPreCommit(ExecutionContextImpl.java:740)
at org.datanucleus.transaction.TransactionImpl.internalPreCommit(TransactionImpl.java:398)
at org.datanucleus.transaction.TransactionImpl.commit(TransactionImpl.java:288)
at org.datanucleus.api.jdo.JDOTransaction.commit(JDOTransaction.java:94)
... 13 common frames omitted

Also seeing some interesting NPM/Java errors

2024-02-06 02:38:21,699 ERROR [NpmMetaAnalyzer] Request failure
�java.net.URISyntaxException: Illegal character in path at index 43: https://registry.npmjs.org/-/package/jquery joyride plugin /dist-tags
at java.base/java.net.URI$Parser.fail(Unknown Source)
at java.base/java.net.URI$Parser.checkChars(Unknown Source)
at java.base/java.net.URI$Parser.parseHierarchical(Unknown Source)
at java.base/java.net.URI$Parser.parse(Unknown Source)
at java.base/java.net.URI.(Unknown Source)
at org.apache.http.client.utils.URIBuilder.(URIBuilder.java:82)
at org.dependencytrack.tasks.repositories.AbstractMetaAnalyzer.processHttpRequest(AbstractMetaAnalyzer.java:98)
at org.dependencytrack.tasks.repositories.NpmMetaAnalyzer.analyze(NpmMetaAnalyzer.java:78)
at org.dependencytrack.tasks.repositories.RepositoryMetaAnalyzerTask.analyze(RepositoryMetaAnalyzerTask.java:177)
at org.dependencytrack.tasks.repositories.RepositoryMetaAnalyzerTask.lambda$analyze$0(RepositoryMetaAnalyzerTask.java:121)
at io.github.resilience4j.retry.Retry.lambda$decorateCallable$5(Retry.java:237)
at io.github.resilience4j.retry.Retry.executeCallable(Retry.java:373)
at org.dependencytrack.util.CacheStampedeBlocker.readThroughOrPopulateCache(CacheStampedeBlocker.java:201)
at org.dependencytrack.tasks.repositories.RepositoryMetaAnalyzerTask.analyze(RepositoryMetaAnalyzerTask.java:126)
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)
2024-02-06 02:38:21,705 WARN [CacheStampedeBlocker] An error occurred while populating cache repositoryMetaCache for key pkg:npm/jquery%20joyride%20plugin%20@2.1 : java.lang.NullPointerException: Cannot invoke "org.apache.http.client.methods.CloseableHttpResponse.getStatusLine()" because "response" is null
�org.dependencytrack.exception.MetaAnalyzerException: java.lang.NullPointerException: Cannot invoke "org.apache.http.client.methods.CloseableHttpResponse.getStatusLine()" because "response" is null
at org.dependencytrack.tasks.repositories.NpmMetaAnalyzer.analyze(NpmMetaAnalyzer.java:94)
at org.dependencytrack.tasks.repositories.RepositoryMetaAnalyzerTask.analyze(RepositoryMetaAnalyzerTask.java:177)
at org.dependencytrack.tasks.repositories.RepositoryMetaAnalyzerTask.lambda$analyze$0(RepositoryMetaAnalyzerTask.java:121)
at io.github.resilience4j.retry.Retry.lambda$decorateCallable$5(Retry.java:237)
at io.github.resilience4j.retry.Retry.executeCallable(Retry.java:373)
at org.dependencytrack.util.CacheStampedeBlocker.readThroughOrPopulateCache(CacheStampedeBlocker.java:201)
at org.dependencytrack.tasks.repositories.RepositoryMetaAnalyzerTask.analyze(RepositoryMetaAnalyzerTask.java:126)
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: java.lang.NullPointerException: Cannot invoke "org.apache.http.client.methods.CloseableHttpResponse.getStatusLine()" because "response" is null
at org.dependencytrack.tasks.repositories.NpmMetaAnalyzer.analyze(NpmMetaAnalyzer.java:79)
... 11 common frames omitted

Test 4 - Uploaded a 2.1MB SBOM (v1.5)

BOM was uploaded successfully, but still seeing some of those errors from step 3 into step 4

2024-02-06 02:48:13,251 INFO [BomUploadProcessingTaskV2] Consuming uploaded BOM [bomSerialNumber=bbe297cb-3f28-4877-abcf-2ae2b6969eb4, bomFormat=CycloneDX, bomUploadToken=729c66ee-325f-48f1-9f7c-dee49ee74d97, projectName=test 3, bomSpecVersion=1.5, projectUuid=4363b3bd-66af-47ae-93b0-b335c91e510f, projectVersion=null, bomVersion=1]
�2024-02-06 02:48:13,268 INFO [BomUploadProcessingTaskV2] Consumed 826 components (846 before de-duplication), 0 services (0 before de-duplication), and 0 dependency graph entries [bomSerialNumber=bbe297cb-3f28-4877-abcf-2ae2b6969eb4, bomFormat=CycloneDX, bomUploadToken=729c66ee-325f-48f1-9f7c-dee49ee74d97, projectName=test 3, bomSpecVersion=1.5, projectUuid=4363b3bd-66af-47ae-93b0-b335c91e510f, projectVersion=null, bomVersion=1]
2024-02-06 02:48:13,270 INFO [BomUploadProcessingTaskV2] Processing 826 components [bomSerialNumber=bbe297cb-3f28-4877-abcf-2ae2b6969eb4, bomFormat=CycloneDX, bomUploadToken=729c66ee-325f-48f1-9f7c-dee49ee74d97, projectName=test 3, bomSpecVersion=1.5, projectUuid=4363b3bd-66af-47ae-93b0-b335c91e510f, projectVersion=null, bomVersion=1]
2024-02-06 02:48:13,510 INFO [BomUploadProcessingTaskV2] Processing 0 services [bomSerialNumber=bbe297cb-3f28-4877-abcf-2ae2b6969eb4, bomFormat=CycloneDX, bomUploadToken=729c66ee-325f-48f1-9f7c-dee49ee74d97, projectName=test 3, bomSpecVersion=1.5, projectUuid=4363b3bd-66af-47ae-93b0-b335c91e510f, projectVersion=null, bomVersion=1]
2024-02-06 02:48:13,510 INFO [BomUploadProcessingTaskV2] Processing 0 dependency graph entries [bomSerialNumber=bbe297cb-3f28-4877-abcf-2ae2b6969eb4, bomFormat=CycloneDX, bomUploadToken=729c66ee-325f-48f1-9f7c-dee49ee74d97, projectName=test 3, bomSpecVersion=1.5, projectUuid=4363b3bd-66af-47ae-93b0-b335c91e510f, projectVersion=null, bomVersion=1]
2024-02-06 02:48:13,529 INFO [BomUploadProcessingTaskV2] BOM processed successfully in 00:00:00.324 [bomSerialNumber=bbe297cb-3f28-4877-abcf-2ae2b6969eb4, bomFormat=CycloneDX, bomUploadToken=729c66ee-325f-48f1-9f7c-dee49ee74d97, projectName=test 3, bomSpecVersion=1.5, projectUuid=4363b3bd-66af-47ae-93b0-b335c91e510f, projectVersion=null, bomVersion=1]
�2024-02-06 02:48:13,536 INFO [RepositoryMetaAnalyzerTask] Performing component repository metadata analysis against 826 components
2024-02-06 02:48:13,699 INFO [InternalAnalysisTask] Starting internal analysis task
2024-02-06 02:48:13,699 INFO [InternalAnalysisTask] Analyzing 826 component(s)
2024-02-06 02:48:14,123 ERROR [NpmMetaAnalyzer] Request failure
�java.net.URISyntaxException: Illegal character in path at index 43: https://registry.npmjs.org/-/package/jquery ui position/dist-tags
at java.base/java.net.URI$Parser.fail(Unknown Source)
at java.base/java.net.URI$Parser.checkChars(Unknown Source)
at java.base/java.net.URI$Parser.parseHierarchical(Unknown Source)
at java.base/java.net.URI$Parser.parse(Unknown Source)
at java.base/java.net.URI.(Unknown Source)
at org.apache.http.client.utils.URIBuilder.(URIBuilder.java:82)
at org.dependencytrack.tasks.repositories.AbstractMetaAnalyzer.processHttpRequest(AbstractMetaAnalyzer.java:98)
at org.dependencytrack.tasks.repositories.NpmMetaAnalyzer.analyze(NpmMetaAnalyzer.java:78)

nscuro added a commit to nscuro/dependency-track that referenced this pull request Feb 8, 2024
As reported in DependencyTrack#3357 (comment)

Signed-off-by: nscuro <nscuro@protonmail.com>
@nscuro
Copy link
Member Author

nscuro commented Feb 24, 2024

@melba-lopez I resolved the NPM issue in #3456.
The OSS Index issue with a reference URL that is too long is not related to this change.

I have received some more feedback via Slack, and it doesn't look like people are running into any issues due to this change. However, I still want to play it safe, so I'll keep it behind a feature flag for now. We will encourage folks to enable it when upgrading, but they can also still fall back in case something about the change breaks their workflows.

@nscuro nscuro merged commit 16b6d78 into DependencyTrack:master Feb 24, 2024
9 checks passed
@nscuro nscuro deleted the refactor-bom-upload-processing branch February 24, 2024 10:19
mikael-carneholm-2-wcar pushed a commit to mikael-carneholm-2-wcar/dependency-track that referenced this pull request Mar 15, 2024
As reported in DependencyTrack#3357 (comment)

Signed-off-by: nscuro <nscuro@protonmail.com>
Signed-off-by: Mikael Carneholm <mikael.carneholm.2@wirelesscar.com>
@github-actions github-actions bot locked as resolved and limited conversation to collaborators Mar 26, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.