Error running AMR detection plugin

[glwinsor]

The workflow seems to fail quickly on the IRIDA web application side and the Galaxy log suggests staramr is failing due to a problem executing tool: dataset_collections:

There was a failure executing a job for tool [toolshed.g2.bx.psu.edu/repos/nml/staramr/staramr_search/0.4.0] - Error executing tool: 'dataset_collections'

I'm using Galaxy 17.09 with RGI 4.2.2, StarAMR 0.4.0 and Shovill 1.0.4. There were some problems installing RGI via Galaxy but I have upgraded to conda 4.6 and reinstalled these dependencies via command line as well.

Here is the output from the Tomcat log which mentions "Uncaught exception in exposed API method:"

05 May 2019 20:48:19,076 DEBUG ca.corefacility.bioinformatics.irida.ria.web.DashboardController:23 - Displaying dashboard page 05 May 2019 20:48:19,393 DEBUG ca.corefacility.bioinformatics.irida.ria.web.LoginController:62 - User is already logged in. 05 May 2019 20:48:19,394 DEBUG ca.corefacility.bioinformatics.irida.ria.web.DashboardController:23 - Displaying dashboard page 05 May 2019 20:48:19,396 DEBUG ca.corefacility.bioinformatics.irida.ria.web.DashboardController:23 - Displaying dashboard page 05 May 2019 20:48:19,398 DEBUG ca.corefacility.bioinformatics.irida.ria.web.LoginController:62 - User is already logged in. 05 May 2019 20:48:27,422 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.execution.galaxy.AnalysisExecutionServiceGalaxyCleanupAsync:81 - Cleaning up AnalysisSubmission [id=144, name=amr-detection_20190505_SRR3028745, submitter=admin, workflowId=b1a0fd27-2948-41c1-aecc-8f541f1d5dbd, analysisState=ERROR, analysisCleanedState=CLEANING] 05 May 2019 20:49:19,945 DEBUG ca.corefacility.bioinformatics.irida.service.impl.AnalysisExecutionScheduledTaskImpl:108 - Preparing AnalysisSubmission [id=147, name=amr-detection_20190505_476478, submitter=admin, workflowId=b1a0fd27-2948-41c1-aecc-8f541f1d5dbd, analysisState=NEW, analysisCleanedState=NOT_CLEANED] 05 May 2019 20:49:19,961 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.execution.galaxy.AnalysisExecutionServiceGalaxyAsync:105 - Preparing submission for AnalysisSubmission [id=147, name=amr-detection_20190505_476478, submitter=admin, workflowId=b1a0fd27-2948-41c1-aecc-8f541f1d5dbd, analysisState=PREPARING, analysisCleanedState=NOT_CLEANED] 05 May 2019 20:49:28,879 DEBUG ca.corefacility.bioinformatics.irida.service.impl.AnalysisExecutionScheduledTaskImpl:138 - Executing AnalysisSubmission [id=147, name=amr-detection_20190505_476478, submitter=admin, workflowId=b1a0fd27-2948-41c1-aecc-8f541f1d5dbd, analysisState=PREPARED, analysisCleanedState=NOT_CLEANED] 05 May 2019 20:49:28,892 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.execution.galaxy.AnalysisExecutionServiceGalaxyAsync:143 - Running submission for AnalysisSubmission [id=147, name=amr-detection_20190505_476478, submitter=admin, workflowId=b1a0fd27-2948-41c1-aecc-8f541f1d5dbd, analysisState=SUBMITTING, analysisCleanedState=NOT_CLEANED] 05 May 2019 20:49:29,310 DEBUG ca.corefacility.bioinformatics.irida.pipeline.upload.galaxy.GalaxyLibrariesService:121 - Created library=AnalysisSubmission-40e393f3-0341-4465-a7b8-4135b59c7b60 libraryId=e8d3f6db536fde44 05 May 2019 20:49:29,381 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.workspace.galaxy.AnalysisParameterServiceGalaxy:87 - Setting parameter iridaName=shovill-1-adv.nocorr, galaxyToolId=toolshed.g2.bx.psu.edu/repos/iuc/shovill/shovill/1.0.4, galaxyParameterName=adv.nocorr, value=false 05 May 2019 20:49:29,382 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.workspace.galaxy.AnalysisParameterServiceGalaxy:87 - Setting parameter iridaName=shovill-1-adv.mincov, galaxyToolId=toolshed.g2.bx.psu.edu/repos/iuc/shovill/shovill/1.0.4, galaxyParameterName=adv.mincov, value=1 05 May 2019 20:49:29,382 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.workspace.galaxy.AnalysisParameterServiceGalaxy:87 - Setting parameter iridaName=shovill-1-trim, galaxyToolId=toolshed.g2.bx.psu.edu/repos/iuc/shovill/shovill/1.0.4, galaxyParameterName=trim, value=false 05 May 2019 20:49:29,382 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.workspace.galaxy.AnalysisParameterServiceGalaxy:87 - Setting parameter iridaName=shovill-1-adv.namefmt, galaxyToolId=toolshed.g2.bx.psu.edu/repos/iuc/shovill/shovill/1.0.4, galaxyParameterName=adv.namefmt, value=contig%05d 05 May 2019 20:49:29,382 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.workspace.galaxy.AnalysisParameterServiceGalaxy:87 - Setting parameter iridaName=shovill-1-adv.depth, galaxyToolId=toolshed.g2.bx.psu.edu/repos/iuc/shovill/shovill/1.0.4, galaxyParameterName=adv.depth, value=100 05 May 2019 20:49:29,382 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.workspace.galaxy.AnalysisParameterServiceGalaxy:73 - Parameter with name=shovill-1-adv.gsize will ignore the default value= 05 May 2019 20:49:29,383 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.workspace.galaxy.AnalysisParameterServiceGalaxy:73 - Parameter with name=shovill-1-adv.kmers will ignore the default value= 05 May 2019 20:49:29,383 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.workspace.galaxy.AnalysisParameterServiceGalaxy:73 - Parameter with name=shovill-1-adv.opts will ignore the default value= 05 May 2019 20:49:29,383 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.workspace.galaxy.AnalysisParameterServiceGalaxy:87 - Setting parameter iridaName=shovill-1-adv.minlen, galaxyToolId=toolshed.g2.bx.psu.edu/repos/iuc/shovill/shovill/1.0.4, galaxyParameterName=adv.minlen, value=1 05 May 2019 20:49:29,383 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.workspace.galaxy.AnalysisParameterServiceGalaxy:87 - Setting parameter iridaName=shovill-1-assembler, galaxyToolId=toolshed.g2.bx.psu.edu/repos/iuc/shovill/shovill/1.0.4, galaxyParameterName=assembler, value=spades 05 May 2019 20:49:29,384 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.workspace.galaxy.AnalysisParameterServiceGalaxy:87 - Setting parameter iridaName=staramr-2-advanced.exclude_negatives, galaxyToolId=toolshed.g2.bx.psu.edu/repos/nml/staramr/staramr_search/0.4.0, galaxyParameterName=advanced.exclude_negatives, value=false 05 May 2019 20:49:29,384 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.workspace.galaxy.AnalysisParameterServiceGalaxy:87 - Setting parameter iridaName=staramr-2-advanced.plength_resfinder, galaxyToolId=toolshed.g2.bx.psu.edu/repos/nml/staramr/staramr_search/0.4.0, galaxyParameterName=advanced.plength_resfinder, value=60.0 05 May 2019 20:49:29,384 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.workspace.galaxy.AnalysisParameterServiceGalaxy:87 - Setting parameter iridaName=staramr-2-use_pointfinder.enable, galaxyToolId=toolshed.g2.bx.psu.edu/repos/nml/staramr/staramr_search/0.4.0, galaxyParameterName=use_pointfinder.enable, value=true 05 May 2019 20:49:29,384 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.workspace.galaxy.AnalysisParameterServiceGalaxy:87 - Setting parameter iridaName=staramr-2-advanced.plength_pointfinder, galaxyToolId=toolshed.g2.bx.psu.edu/repos/nml/staramr/staramr_search/0.4.0, galaxyParameterName=advanced.plength_pointfinder, value=95.0 05 May 2019 20:49:29,384 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.workspace.galaxy.AnalysisParameterServiceGalaxy:87 - Setting parameter iridaName=staramr-2-use_pointfinder.organism, galaxyToolId=toolshed.g2.bx.psu.edu/repos/nml/staramr/staramr_search/0.4.0, galaxyParameterName=use_pointfinder.organism, value=salmonella 05 May 2019 20:49:29,385 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.workspace.galaxy.AnalysisParameterServiceGalaxy:87 - Setting parameter iridaName=staramr-2-advanced.exclude_resistance_phenotypes, galaxyToolId=toolshed.g2.bx.psu.edu/repos/nml/staramr/staramr_search/0.4.0, galaxyParameterName=advanced.exclude_resistance_phenotypes, value=false 05 May 2019 20:49:29,385 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.workspace.galaxy.AnalysisParameterServiceGalaxy:87 - Setting parameter iridaName=staramr-2-advanced.report_all_blast, galaxyToolId=toolshed.g2.bx.psu.edu/repos/nml/staramr/staramr_search/0.4.0, galaxyParameterName=advanced.report_all_blast, value=false 05 May 2019 20:49:29,385 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.workspace.galaxy.AnalysisParameterServiceGalaxy:87 - Setting parameter iridaName=staramr-2-advanced.pid_threshold, galaxyToolId=toolshed.g2.bx.psu.edu/repos/nml/staramr/staramr_search/0.4.0, galaxyParameterName=advanced.pid_threshold, value=98.0 05 May 2019 20:49:29,385 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.workspace.galaxy.AnalysisParameterServiceGalaxy:87 - Setting parameter iridaName=rgi-3-low_quality, galaxyToolId=toolshed.g2.bx.psu.edu/repos/card/rgi/rgi/4.2.2, galaxyParameterName=low_quality, value=false 05 May 2019 20:49:29,385 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.workspace.galaxy.AnalysisParameterServiceGalaxy:87 - Setting parameter iridaName=rgi-3-alignment_tool, galaxyToolId=toolshed.g2.bx.psu.edu/repos/card/rgi/rgi/4.2.2, galaxyParameterName=alignment_tool, value=diamond 05 May 2019 20:49:29,386 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.workspace.galaxy.AnalysisParameterServiceGalaxy:87 - Setting parameter iridaName=rgi-3-data, galaxyToolId=toolshed.g2.bx.psu.edu/repos/card/rgi/rgi/4.2.2, galaxyParameterName=data, value=NA 05 May 2019 20:49:29,386 DEBUG ca.corefacility.bioinformatics.irida.service.analysis.workspace.galaxy.AnalysisParameterServiceGalaxy:87 - Setting parameter iridaName=rgi-3-include_loose, galaxyToolId=toolshed.g2.bx.psu.edu/repos/card/rgi/rgi/4.2.2, galaxyParameterName=include_loose, value=false 05 May 2019 20:50:15,778 DEBUG ca.corefacility.bioinformatics.irida.pipeline.upload.galaxy.GalaxyHistoriesService:219 - Transfered library dataset c8954358b73dd0e0 to history 2f4933c7d721d5e8 dataset id 2833f63046051264 05 May 2019 20:50:15,921 DEBUG ca.corefacility.bioinformatics.irida.pipeline.upload.galaxy.GalaxyHistoriesService:219 - Transfered library dataset 42f5f51e463e55fe to history 2f4933c7d721d5e8 dataset id 38d70f8d07b5883c 05 May 2019 20:50:16,471 ERROR ca.corefacility.bioinformatics.irida.service.analysis.execution.AnalysisExecutionServiceAspect:63 - Error occured for submission: AnalysisSubmission [id=147, name=amr-detection_20190505_476478, submitter=admin, workflowId=b1a0fd27-2948-41c1-aecc-8f541f1d5dbd, analysisState=SUBMITTING, analysisCleanedState=NOT_CLEANED] changing to state ERROR ca.corefacility.bioinformatics.irida.exceptions.WorkflowException: GalaxyResponseException{status=500, responseBody={"err_msg": "Uncaught exception in exposed API method:", "err_code": 0}, errorMessage=Uncaught exception in exposed API method:, errorCode=0, traceback=null} at ca.corefacility.bioinformatics.irida.pipeline.upload.galaxy.GalaxyWorkflowService.runWorkflow(GalaxyWorkflowService.java:123) at ca.corefacility.bioinformatics.irida.service.analysis.execution.galaxy.AnalysisExecutionServiceGalaxyAsync.executeAnalysis(AnalysisExecutionServiceGalaxyAsync.java:151) at ca.corefacility.bioinformatics.irida.service.analysis.execution.galaxy.AnalysisExecutionServiceGalaxyAsync$$FastClassBySpringCGLIB$$fc2d896.invoke(<generated>) at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:718) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:85) at ca.corefacility.bioinformatics.irida.service.analysis.annotations.RunAsUserAspect.setSecurityContextFromAnalysisSubmission(RunAsUserAspect.java:100) at sun.reflect.GeneratedMethodAccessor830.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621) at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610) at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:68) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:168) at org.springframework.aop.aspectj.AspectJAfterThrowingAdvice.invoke(AspectJAfterThrowingAdvice.java:58) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:168) at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.interceptor.AsyncExecutionInterceptor$1.call(AsyncExecutionInterceptor.java:108) at org.springframework.security.concurrent.DelegatingSecurityContextCallable.call(DelegatingSecurityContextCallable.java:60) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) Caused by: GalaxyResponseException{status=500, responseBody={"err_msg": "Uncaught exception in exposed API method:", "err_code": 0}, errorMessage=Uncaught exception in exposed API method:, errorCode=0, traceback=null} at com.github.jmchilton.blend4j.galaxy.Client.buildResponseException(Client.java:18) at com.github.jmchilton.blend4j.BaseClient.checkResponse(BaseClient.java:138) at com.github.jmchilton.blend4j.BaseClient.create(BaseClient.java:47) at com.github.jmchilton.blend4j.BaseClient.create(BaseClient.java:36) at com.github.jmchilton.blend4j.BaseClient.create(BaseClient.java:32) at com.github.jmchilton.blend4j.galaxy.WorkflowsClientImpl.runWorkflowResponse(WorkflowsClientImpl.java:38) at com.github.jmchilton.blend4j.galaxy.WorkflowsClientImpl.runWorkflow(WorkflowsClientImpl.java:42) at ca.corefacility.bioinformatics.irida.pipeline.upload.galaxy.GalaxyWorkflowService.runWorkflow(GalaxyWorkflowService.java:121) ... 24 more 05 May 2019 21:24:14,365 DEBUG ca.corefacility.bioinformatics.irida.ria.web.LoginController:66 - Displaying login page. 05 May 2019 21:24:16,775 DEBUG org.springframework.security.web.authentication.AbstractAuthenticationTargetUrlRequestHandler:107 - Using default Url: / 05 May 2019 21:24:16,801 DEBUG ca.corefacility.bioinformatics.irida.ria.web.DashboardController:23 - Displaying dashboard page

It doesn't make sense to me because shovill should run before staramr and Shovill appears to return a valid assembly when I review the history in Galaxy.

I've enclosed the Galaxy paster.log below containing everything from startup to the point of workflow failing. Does anything stand out to you?

Thanks, Geoff

paster.log

[apetkau]

Hello @glwinsor

I haven't quite figured out what the error is yet. Are you able to upload files and the workflow directly to Galaxy and run that way? The workflow you can find at https://github.com/phac-nml/irida-plugin-amr-detection/blob/development/src/main/resources/workflows/0.1.0/irida_workflow_structure.ga.

What I tried so far is to install Galaxy version 17.09 and test out linking to IRIDA (since I am using 18.09 here). But, using the older version of Galaxy didn't make a difference.

I did encounter similar issues as you with conda though (e.g., slowness, and not installing certain packages), but those were all fixed by updating conda (which for some reason I had to run conda update conda multiple times since it didn't fully upgrade the first time).

I'll keep on looking into this.

[glwinsor]

I agree! I updated to the most recent conda (4.6) and that made a big difference! Let me try uploading the workflow and see what happens. Thanks.

[glwinsor]

It looks to me like staramr is running at the same time as shovill (immediately after starting the workflow). I saw the same thing executing the IRIDA-submitted workflow via galaxy interface.

I went back to the previous workflow submitted via Galaxy and staramr is still running 16 hours later after Shovill completed.

[apetkau]

Thanks @glwinsor. I think the reason staramr appears to be running before shovill is because of the way the hits/ output files are detected. They are detected at runtime (since it's unknown how many blast hits you will get until runtime). I believe Galaxy then displays this dataset as if it were running, but really it's not (at least not until shovill finishes).,

[glwinsor]

Hi @apetkau . It looks like staramr is still running almost 20 hours later. Which hits were you referring to in your previous post? Is it expecting output from something other than shovill which appears to have completed OK?

I suspect this issue is due to something that went wrong while conda was installing one of the tools. There's a high degree of file system latency(but not disk latency) on cedar while file metadata is being looked up. With all of the tiny files being used by conda, I wonder if something is timing out. I tried installing the tools using conda from the command line but maybe something that Galaxy needs to set is missing too?

[apetkau]

The hits I was referring to was this dataset in the screenshot you provided:

This will appear to start (e.g., show up in yellow) at the same time as shovill, even though it's actually waiting for the shovill results before it finishes.

Are both shovill and rgi all finished running, and it's just staramr that's running? Is here an actual job scheduled (or in queue) on our cluster for staramr, or is it just Galaxy that shows it as running?

The conda latency issue could contribute to this problem. You could try loading up the conda environment yourself used by Galaxy conda activate __staramr@0.4.0 or source activate __staramr@0.4.0 and then running staramr --version to see if it's working (or if it's slow).

[glwinsor]

Just ran the RGI tool in Galaxy taking input from shovill dataset. It worked great.

I then ran staramr and got a popup error message similar to what I see in the galaxy log while running it from IRIDA.

The server could not complete the request. Please contact the Galaxy Team if this error persists. Error executing tool: 'dataset_collections' { "tool_id": "toolshed.g2.bx.psu.edu/repos/nml/staramr/staramr_search/0.5.0", "tool_version": "0.5.0", "inputs": { "genomes": { "values": [ { "src": "hdca", "name": "Shovill on collection 3: Contigs", "tags": [], "keep": false, "hid": 4, "id": "9760eb3e17fb6bd0" } ], "batch": false }, "use_pointfinder": "salmonella", "advanced|pid_threshold": 98, "advanced|plength_resfinder": 60, "advanced|plength_pointfinder": 95, "advanced|plength_plasmidfinder": 60, "advanced|report_all_blast": "false", "advanced|exclude_negatives": "false", "advanced|exclude_resistance_phenotypes": "false", "advanced|exclude_genes|exclude_genes_condition": "default", "advanced|plasmidfinder_type": "include_all" } }

It's a little hard to read so here is the best screenshot I could do:

Here are the settings I used. Note I tried it for both 0.4.0 and 0.5.0:

[glwinsor]

@apetkau I missed one of your previous questions: when running the entire pipeline, RGI never gets to run.

[apetkau]

Hey @glwinsor, thanks. Another question I have, which exact commit are you on for your Galaxy instance? And which branch/tag?

I found this issue https://github.com/galaxyproject/galaxy/issues/4975 which describes the exact exception you are encountering. It looks like it was fixed in https://github.com/galaxyproject/galaxy/pull/4984, which should have been merged into the Galaxy branch release_17.09. However, it is not present in the Galaxy tag v17.09.

I can confirm that I get the same failure for tag v17.09, but not for branch release_17.09. I can also confirm that the exact code changes in that pull request fix the issue (I tried applying that commit to the tag, and it all worked).

So, for a solution you will have to update Galaxy to the latest fixes found in the release_17.09 branch (there's a bit of documentation here https://galaxyproject.org/admin/maintenance/). Alternatively, you could apply that one commit and restart Galaxy (though then you won't get any of the other issues fixed since 17.09 was initially released).