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.69k stars 578 forks source link

HTTP 500 response from Lookup API #498

Open msymons opened 5 years ago

msymons commented 5 years ago

Current Behavior:

After installing dependency-track plugin 2.2.0 (released 4 November 2019) and updating pipelines that use "name + version" to start using synchronous mode, I have many pipeline jobs that seem to be publishing fine. However, I have at least one that is failing the build with an HTTP 500 error.

Steps to Reproduce:

Not quite sure, as the logging in neither server nor jenkins plugin is quite telling me what is being submitted.

However, this is what should have been submitted to lookup:

I deleted the project in DT and it was then correctly recreated by the pipeline using the above name/version.

Expected Behavior:

1) DT should really be generating an HTTP 400 response instead of HTTP 500... and provide content that contains information on what went wrong. However, the API does not document HTTP 400, 2) Separate to DT... it would help if the publisher provided more information on what it is doing. eg, what name and version it is submitting to lookup, etc.

Environment:

Additional Details:

From Jenkins Console logging for build...

14:28:56  [DependencyTrack] Publishing artifact to Dependency-Track - https://dependency-track.xxxxxxxx.com
14:28:56  [DependencyTrack] The artifact was successfully published
14:29:06  [DependencyTrack] Polling Dependency-Track for BOM processing status
14:29:06  [DependencyTrack] Processing findings
14:29:06  [DependencyTrack] An error occurred while retrieving findings - HTTP response code: 500 Server Error

Compare with a job that is working fine:

14:39:04  [DependencyTrack] Publishing artifact to Dependency-Track - https://dependency-track.xxxxxxxx.com
14:39:04  [DependencyTrack] The artifact was successfully published
14:39:14  [DependencyTrack] Polling Dependency-Track for BOM processing status
14:39:24  [DependencyTrack] Polling Dependency-Track for BOM processing status
14:39:34  [DependencyTrack] Polling Dependency-Track for BOM processing status
14:39:34  [DependencyTrack] Looking up id of newly created project
14:39:34  [DependencyTrack] Processing findings

From dependency-track.log for problem job:

2019-11-04 14:28:56,816 [] INFO [org.dependencytrack.tasks.BomUploadProcessingTask] Processing CycloneDX BOM uploaded to project: 121b68c0-a52f-4374-b936-6df7d7bd1b19
2019-11-04 14:29:05,483 [] INFO [org.dependencytrack.tasks.BomUploadProcessingTask] Processed 64 components uploaded to project 121b68c0-a52f-4374-b936-6df7d7bd1b19
2019-11-04 14:29:05,692 [] INFO [org.dependencytrack.tasks.scanners.InternalAnalysisTask] Starting internal analysis task
2019-11-04 14:29:05,700 [] INFO [org.dependencytrack.tasks.scanners.InternalAnalysisTask] Internal analysis complete
2019-11-04 14:29:05,702 [] INFO [org.dependencytrack.tasks.MetricsUpdateTask] Executing metrics update for project: 121b68c0-a52f-4374-b936-6df7d7bd1b19
2019-11-04 14:29:05,714 [] INFO [org.dependencytrack.tasks.MetricsUpdateTask] Executing metrics update for project: 121b68c0-a52f-4374-b936-6df7d7bd1b19
2019-11-04 14:29:09,652 [] INFO [org.dependencytrack.tasks.MetricsUpdateTask] Completed metrics update for project: 121b68c0-a52f-4374-b936-6df7d7bd1b19
2019-11-04 14:29:09,716 [] INFO [org.dependencytrack.tasks.MetricsUpdateTask] Completed metrics update for project: 121b68c0-a52f-4374-b936-6df7d7bd1b19

Note that metrics are executed twice. Is this intended?

From Dependency-Track server.log

2019-11-04 14:29:06,831 [] WARN [org.eclipse.jetty.server.HttpChannel] /api/v1/finding/project/null
javax.servlet.ServletException: java.lang.IllegalArgumentException: Invalid UUID string: null
    at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:408)
    at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:346)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:365)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:318)
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:205)
    at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:852)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1604)
    at alpine.filters.ContentSecurityPolicyFilter.doFilter(ContentSecurityPolicyFilter.java:224)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1591)
    at alpine.filters.ClickjackingFilter.doFilter(ClickjackingFilter.java:92)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1591)
    at alpine.filters.WhitelistUrlFilter.doFilter(WhitelistUrlFilter.java:115)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1583)
    at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:542)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
    at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:536)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235)
    at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1581)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
    at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1307)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
    at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:482)
    at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1549)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
    at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1204)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
    at org.eclipse.jetty.server.Server.handle(Server.java:494)
    at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:374)
    at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:268)
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
    at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
    at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:367)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:782)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:918)
    at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.IllegalArgumentException: Invalid UUID string: null
    at java.util.UUID.fromString(UUID.java:194)
    at alpine.persistence.AbstractAlpineQueryManager.getObjectByUuid(AbstractAlpineQueryManager.java:534)
    at org.dependencytrack.resources.v1.FindingResource.getFindingsByProject(FindingResource.java:69)
    at sun.reflect.GeneratedMethodAccessor312.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    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:124)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:167)
    at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:176)
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:79)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:469)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:391)
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:80)
    at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:253)
    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:232)
    at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:680)
    at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:392)
    ... 41 common frames omitted
msymons commented 5 years ago

I discovered what was wrong. ONE Jenkins server failed to upgrade to the new dependency-track plugin 2.2.0 and, of course, it was the one with the "GitHub Stats" job.

After the plugin was updated for real, the job is now OK.

Therefore, this issue is not a defect. But I do think it warrants labelling as an enhancement... that Dependency-Track should be returning HTTP 400 and not HTTP 500 in such cases.