search

oschwengers / asap

A scalable bacterial genome assembly, annotation and analysis pipeline
https://doi.org/10.1371/journal.pcbi.1007134
GNU General Public License v3.0
70 stars 19 forks source link

max waiting period (86400000 s) exceeded! #22

Closed brittonstrickland closed 2 years ago

brittonstrickland commented 3 years ago

Hi all,

I successfully ran 1 genome through ASA3P and planned to run 3 more genomes through the pipeline. The 1 genome that had previously been run was successful. However, when the pipeline got to genomes 2 and 3, there are several steps that resulted in the warning "max waiting period (86400000 s) exceeded!". For both of these 2 failed genomes, the pipeline was able to complete the QC, Mapping, and SNP step. However, the VFDetection, Taxonomy, MLST, ABR, Annotation, and Scaffolding step all failed due to the max waiting period warning, which resulted in several other steps being skipped.

Could this be due to a memory issue or machine issue? I don't expect this, since one genome was successfully pushed through the pipeline. I am currently running on an iMac with Docker Container with an allocated 6 CPUs and 12gb memory.

I have also attached my ASAP.log file for reference.

2021-07-22 20:26:56.521 INFO [main] bio.comp.jlu.asap.ASAP : version: 1.3.0 2021-07-22 20:26:56.536 INFO [main] bio.comp.jlu.asap.ASAP : project-path: /data 2021-07-22 20:26:56.537 INFO [main] bio.comp.jlu.asap.ASAP : command line: [--project-dir, /data, --local] 2021-07-22 20:26:56.867 INFO [main] bio.comp.jlu.asap.ASAP : option: none -> normal execution 2021-07-22 20:26:56.871 INFO [main] bio.comp.jlu.asap.ASAP : execution mode: local 2021-07-22 20:26:56.873 INFO [main] bio.comp.jlu.asap.ASAP : slot size: 1 2021-07-22 20:26:57.492 INFO [Thread-4] b.c.j.asap.steps.GenomeConversions : finished genomeConversions step 2021-07-22 20:27:20.097 INFO [Thread-1] b.c.j.a.steps.ReferenceProcessings : finished referenceProcessings step 2021-07-22 20:27:27.583 INFO [Thread-3] b.c.j.asap.steps.SNPAnnotationSetup : build snpEff database: /data/snps/snpEff.config 2021-07-22 20:27:34.374 INFO [Thread-3] b.c.j.asap.steps.SNPAnnotationSetup : finished snpAnnotationSetup step 2021-07-22 20:28:34.104 INFO [Thread-2] b.c.jlu.asap.steps.MappingIndices : finished mappingIndices step 2021-07-22 20:28:34.275 INFO [ASAP-RUN-THREAD-1] b.c.jlu.asap.genomes.GenomeRunner : start analysis: genome-id=1 2021-07-23 00:04:10.450 INFO [QC-Step-Thread-1] b.comp.jlu.asap.genomes.GenomeStep : finished qc step: genome.id=1 2021-07-23 02:25:41.578 INFO [Mapping-Step-Thread-1] b.comp.jlu.asap.genomes.GenomeStep : finished mapping step: genome.id=1 2021-07-23 04:33:42.487 INFO [SNPDetection-Step-Thread-1] b.comp.jlu.asap.genomes.GenomeStep : finished snps step: genome.id=1 2021-07-23 20:07:54.487 INFO [Assembly-Step-Thread-1] b.comp.jlu.asap.genomes.GenomeStep : finished assembly step: genome.id=1 2021-07-23 20:13:40.248 INFO [Scaffolding-Step-Thread-1] b.comp.jlu.asap.genomes.GenomeStep : finished scaffolding step: genome.id=1 2021-07-23 20:14:06.188 INFO [MLST-Step-Thread-1] b.comp.jlu.asap.genomes.GenomeStep : finished mlst step: genome.id=1 2021-07-23 20:14:51.117 ERROR [ABRDetection-Step-Thread-1] b.comp.jlu.asap.genomes.GenomeStep : abr step aborted! genome.id=1 java.lang.IllegalStateException: abnormal ABR exit code! exitCode=1 at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.lang.reflect.Constructor.newInstance(Constructor.java:423) at org.codehaus.groovy.reflection.CachedConstructor.invoke(CachedConstructor.java:83) at org.codehaus.groovy.reflection.CachedConstructor.doConstructorInvoke(CachedConstructor.java:77) at org.codehaus.groovy.runtime.callsite.ConstructorSite$ConstructorSiteNoUnwrap.callConstructor(ConstructorSite.java:84) at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCallConstructor(CallSiteArray.java:59) at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callConstructor(AbstractCallSite.java:238) at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callConstructor(AbstractCallSite.java:250) at bio.comp.jlu.asap.genomes.ABRDetectionStep.runStep(ABRDetectionStep.groovy:139) at bio.comp.jlu.asap.genomes.ABRDetectionStep$runStep$2.callCurrent(Unknown Source) at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCallCurrent(CallSiteArray.java:51) at bio.comp.jlu.asap.genomes.AnnotationStep$runStep$2.callCurrent(Unknown Source) at bio.comp.jlu.asap.genomes.GenomeStep.run(GenomeStep.groovy:86) 2021-07-23 20:17:32.503 INFO [Taxonomy-Step-Thread-1] b.comp.jlu.asap.genomes.GenomeStep : finished taxonomy step: genome.id=1 2021-07-23 20:18:14.820 INFO [Annotation-Step-Thread-1] b.comp.jlu.asap.genomes.GenomeStep : finished annotation step: genome.id=1 2021-07-23 20:19:22.527 INFO [VFDetection-Step-Thread-1] b.comp.jlu.asap.genomes.GenomeStep : finished vf step: genome.id=1 2021-07-23 20:19:22.911 INFO [ASAP-RUN-THREAD-1] b.comp.jlu.asap.genomes.GenomeStep : finished pipeline step: genome.id=1 2021-07-23 20:19:23.237 INFO [ASAP-RUN-THREAD-1] b.c.jlu.asap.genomes.GenomeRunner : start analysis: genome-id=2 2021-07-24 00:15:29.353 INFO [QC-Step-Thread-2] b.comp.jlu.asap.genomes.GenomeStep : finished qc step: genome.id=2 2021-07-24 02:06:01.974 INFO [Mapping-Step-Thread-2] b.comp.jlu.asap.genomes.GenomeStep : finished mapping step: genome.id=2 2021-07-24 02:23:24.435 INFO [SNPDetection-Step-Thread-2] b.comp.jlu.asap.genomes.GenomeStep : finished snps step: genome.id=2 2021-07-24 20:19:37.661 WARN [ABRDetection-Step-Thread-2] b.c.j.asap.genomes.ABRDetectionStep : max waiting period (86400000 s) exceeded! 2021-07-24 20:19:37.783 WARN [MLST-Step-Thread-2] bio.comp.jlu.asap.genomes.MLSTStep : max waiting period (86400000 s) exceeded! 2021-07-24 20:19:37.661 WARN [Taxonomy-Step-Thread-2] b.c.jlu.asap.genomes.TaxonomyStep : max waiting period (86400000 s) exceeded! 2021-07-24 20:19:37.781 WARN [VFDetection-Step-Thread-2] b.c.j.asap.genomes.VFDetectionStep : max waiting period (86400000 s) exceeded! 2021-07-24 20:19:37.661 WARN [Scaffolding-Step-Thread-2] b.c.j.asap.genomes.ScaffoldingStep : max waiting period (86400000 s) exceeded! 2021-07-24 20:19:37.661 WARN [Annotation-Step-Thread-2] b.c.jlu.asap.genomes.AnnotationStep : max waiting period (86400000 s) exceeded! 2021-07-24 20:19:39.074 WARN [Annotation-Step-Thread-2] b.comp.jlu.asap.genomes.GenomeStep : skip annotation step! check failed: genome.id=2 2021-07-24 20:19:39.075 WARN [ABRDetection-Step-Thread-2] b.comp.jlu.asap.genomes.GenomeStep : skip abr step! check failed: genome.id=2 2021-07-24 20:19:39.075 WARN [Taxonomy-Step-Thread-2] b.comp.jlu.asap.genomes.GenomeStep : skip taxonomy step! check failed: genome.id=2 2021-07-24 20:19:39.076 WARN [Scaffolding-Step-Thread-2] b.comp.jlu.asap.genomes.GenomeStep : skip scaffolding step! check failed: genome.id=2 2021-07-24 20:19:39.076 WARN [MLST-Step-Thread-2] b.comp.jlu.asap.genomes.GenomeStep : skip mlst step! check failed: genome.id=2 2021-07-24 20:19:39.074 WARN [VFDetection-Step-Thread-2] b.comp.jlu.asap.genomes.GenomeStep : skip vf step! check failed: genome.id=2 2021-07-24 22:53:25.615 INFO [Assembly-Step-Thread-2] b.comp.jlu.asap.genomes.GenomeStep : finished assembly step: genome.id=2 2021-07-24 22:53:26.165 INFO [ASAP-RUN-THREAD-1] b.comp.jlu.asap.genomes.GenomeStep : finished pipeline step: genome.id=2 2021-07-24 22:53:26.494 INFO [ASAP-RUN-THREAD-1] b.c.jlu.asap.genomes.GenomeRunner : start analysis: genome-id=3 2021-07-25 02:36:11.002 INFO [QC-Step-Thread-3] b.comp.jlu.asap.genomes.GenomeStep : finished qc step: genome.id=3 2021-07-25 04:25:00.972 INFO [Mapping-Step-Thread-3] b.comp.jlu.asap.genomes.GenomeStep : finished mapping step: genome.id=3 2021-07-25 04:38:49.827 INFO [SNPDetection-Step-Thread-3] b.comp.jlu.asap.genomes.GenomeStep : finished snps step: genome.id=3 2021-07-25 22:53:41.043 WARN [VFDetection-Step-Thread-3] b.c.j.asap.genomes.VFDetectionStep : max waiting period (86400000 s) exceeded! 2021-07-25 22:53:41.043 WARN [Taxonomy-Step-Thread-3] b.c.jlu.asap.genomes.TaxonomyStep : max waiting period (86400000 s) exceeded! 2021-07-25 22:53:41.674 WARN [MLST-Step-Thread-3] bio.comp.jlu.asap.genomes.MLSTStep : max waiting period (86400000 s) exceeded! 2021-07-25 22:53:41.043 WARN [ABRDetection-Step-Thread-3] b.c.j.asap.genomes.ABRDetectionStep : max waiting period (86400000 s) exceeded! 2021-07-25 22:53:41.043 WARN [Annotation-Step-Thread-3] b.c.jlu.asap.genomes.AnnotationStep : max waiting period (86400000 s) exceeded! 2021-07-25 22:53:41.667 WARN [Scaffolding-Step-Thread-3] b.c.j.asap.genomes.ScaffoldingStep : max waiting period (86400000 s) exceeded! 2021-07-25 22:53:42.484 WARN [ABRDetection-Step-Thread-3] b.comp.jlu.asap.genomes.GenomeStep : skip abr step! check failed: genome.id=3 2021-07-25 22:53:44.163 WARN [VFDetection-Step-Thread-3] b.comp.jlu.asap.genomes.GenomeStep : skip vf step! check failed: genome.id=3 2021-07-25 22:53:44.163 WARN [Annotation-Step-Thread-3] b.comp.jlu.asap.genomes.GenomeStep : skip annotation step! check failed: genome.id=3 2021-07-25 22:53:44.163 WARN [Taxonomy-Step-Thread-3] b.comp.jlu.asap.genomes.GenomeStep : skip taxonomy step! check failed: genome.id=3 2021-07-25 22:53:44.163 WARN [Scaffolding-Step-Thread-3] b.comp.jlu.asap.genomes.GenomeStep : skip scaffolding step! check failed: genome.id=3 2021-07-25 22:53:44.163 WARN [MLST-Step-Thread-3] b.comp.jlu.asap.genomes.GenomeStep : skip mlst step! check failed: genome.id=3 2021-07-26 03:05:28.957 INFO [Assembly-Step-Thread-3] b.comp.jlu.asap.genomes.GenomeStep : finished assembly step: genome.id=3 2021-07-26 03:05:29.021 INFO [ASAP-RUN-THREAD-1] b.comp.jlu.asap.genomes.GenomeStep : finished pipeline step: genome.id=3 2021-07-26 03:06:19.182 INFO [Phylogeny-Analysis-Thread] b.c.jlu.asap.analyses.AnalysisStep : finished phylogeny step 2021-07-26 03:06:25.830 ERROR [CorePan-Analysis-Thread] b.c.jlu.asap.analyses.AnalysisStep : corepan analysis step aborted! java.io.IOException: abnormal core/pan exit code! exitCode=1 at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.lang.reflect.Constructor.newInstance(Constructor.java:423) at org.codehaus.groovy.reflection.CachedConstructor.invoke(CachedConstructor.java:83) at org.codehaus.groovy.reflection.CachedConstructor.doConstructorInvoke(CachedConstructor.java:77) at org.codehaus.groovy.runtime.callsite.ConstructorSite$ConstructorSiteNoUnwrap.callConstructor(ConstructorSite.java:84) at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCallConstructor(CallSiteArray.java:59) at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callConstructor(AbstractCallSite.java:238) at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callConstructor(AbstractCallSite.java:250) at bio.comp.jlu.asap.analyses.CorePanGenomeAnalysis.runStep(CorePanGenomeAnalysis.groovy:118) at bio.comp.jlu.asap.analyses.CorePanGenomeAnalysis$runStep$1.callCurrent(Unknown Source) at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCallCurrent(CallSiteArray.java:51) at bio.comp.jlu.asap.analyses.PhylogenyAnalysis$runStep$1.callCurrent(Unknown Source) at bio.comp.jlu.asap.analyses.AnalysisStep.run(AnalysisStep.groovy:79) 2021-07-26 03:06:25.899 INFO [Analyses-Runner-Thread] b.c.jlu.asap.analyses.AnalysisStep : finished pipeline step 2021-07-26 03:07:19.586 INFO [Thread-55] b.comp.jlu.asap.reports.ReportStep : finished corepan report step 2021-07-26 03:07:23.838 INFO [Thread-44] b.comp.jlu.asap.reports.ReportStep : finished help report step 2021-07-26 03:07:28.920 INFO [Thread-56] b.comp.jlu.asap.reports.ReportStep : finished Phylogeny report step 2021-07-26 03:07:29.837 INFO [Thread-49] b.comp.jlu.asap.reports.ReportStep : finished mlst report step 2021-07-26 03:07:33.426 INFO [Thread-51] b.comp.jlu.asap.reports.ReportStep : finished abr report step 2021-07-26 03:07:54.423 INFO [Thread-53] b.comp.jlu.asap.reports.ReportStep : finished mapping report step 2021-07-26 03:07:57.428 ERROR [Thread-43] b.comp.jlu.asap.reports.ReportStep : index reporting step aborted! java.lang.ArithmeticException: Division undefined at java.math.BigDecimal.divide(BigDecimal.java:1744) at org.codehaus.groovy.runtime.typehandling.BigDecimalMath.divideImpl(BigDecimalMath.java:68) at org.codehaus.groovy.runtime.typehandling.IntegerMath.divideImpl(IntegerMath.java:49) at org.codehaus.groovy.runtime.dgmimpl.NumberNumberDiv$NumberNumber.invoke(NumberNumberDiv.java:323) at org.codehaus.groovy.runtime.callsite.PojoMetaMethodSite.call(PojoMetaMethodSite.java:56) at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:47) at org.codehaus.groovy.runtime.callsite.PojoMetaMethodSite.call(PojoMetaMethodSite.java:58) at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:128) at org.codehaus.groovy.runtime.dgmimpl.NumberNumberDiv$DoubleInteger.call(NumberNumberDiv.java:254) at bio.comp.jlu.asap.reports.IndexReportStep.calcSDev(IndexReportStep.groovy:217) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.codehaus.groovy.runtime.callsite.PogoMetaMethodSite$PogoCachedMethodSiteNoUnwrapNoCoerce.invoke(PogoMetaMethodSite.java:210) at org.codehaus.groovy.runtime.callsite.PogoMetaMethodSite.callCurrent(PogoMetaMethodSite.java:59) at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCallCurrent(CallSiteArray.java:51) at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callCurrent(AbstractCallSite.java:157) at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callCurrent(AbstractCallSite.java:169) at bio.comp.jlu.asap.reports.IndexReportStep.runStep(IndexReportStep.groovy:164) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.codehaus.groovy.runtime.callsite.PogoMetaMethodSite$PogoCachedMethodSiteNoUnwrapNoCoerce.invoke(PogoMetaMethodSite.java:210) at org.codehaus.groovy.runtime.callsite.PogoMetaMethodSite.callCurrent(PogoMetaMethodSite.java:59) at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCallCurrent(CallSiteArray.java:51) at bio.comp.jlu.asap.reports.ReportRunner$runStep$0.callCurrent(Unknown Source) at bio.comp.jlu.asap.reports.ReportStep.run(ReportStep.groovy:104) 2021-07-26 03:07:58.527 INFO [Thread-52] b.comp.jlu.asap.reports.ReportStep : finished vf report step 2021-07-26 03:08:01.997 INFO [Thread-46] b.comp.jlu.asap.reports.ReportStep : finished taxonomy report step 2021-07-26 03:08:07.001 INFO [Thread-45] b.comp.jlu.asap.reports.ReportStep : finished qc report step 2021-07-26 03:08:14.843 INFO [Thread-47] b.comp.jlu.asap.reports.ReportStep : finished assembly report step 2021-07-26 03:10:47.898 INFO [Thread-50] b.comp.jlu.asap.reports.ReportStep : finished annotation report step 2021-07-26 03:11:14.104 INFO [Thread-48] b.comp.jlu.asap.reports.ReportStep : finished scaffolding report step 2021-07-26 03:11:53.130 INFO [Thread-54] b.comp.jlu.asap.reports.ReportStep : finished snps report step 2021-07-26 03:11:53.147 INFO [Report-Runner-Thread] b.comp.jlu.asap.reports.ReportStep : finished pipeline report step

oschwengers commented 3 years ago

Hi @brittonstrickland , thanks for reporting and sorry for the very late reply! As you mention that at least one genome was successfully analyzed I guess that this might be a mere technical issue. The max waiting period (86400000 s) exceeded! check/error was introduce to forestall ASA³P from running forever in case a certain analysis hangs. For instance, this sometimes happens on HPC systems with attached storage. A lack of sufficient storage within the Docker container might also be in issue you could maybe check?

Could you please simply retry the analysis and see if the exact error remains?

oschwengers commented 2 years ago

Hi @brittonstrickland, how is it going with your analysis? Any progress? Does this issue remain? Since this is open for quite a qhile, I'm going to close this for now. However, please, do not hesitate to re-open is just in case the issue remains or you have further questions. Best regards!