Fixed BMDB Nightly testing, and upgrade with better logging

docker_run.sh

@@ -22,6 +22,11 @@ case "$rawCommand" in
     command="export-omex"
     shift
     ;;
+  "test-report")
+    echo 'test-report mode requested'
+    command="test-report"
+    shift
+    ;;
   "export-omex-batch")
     echo 'export-omex-batch mode requested'
     command="export-omex-batch"
@@ -47,6 +52,11 @@ case "$rawCommand" in
     command="execute"
     shift
     ;;
+  "execute-omex")
+      echo 'special testing execution mode requested'
+      command="execute-omex"
+      shift
+      ;;
   "validate")
     echo 'validate mode requested'
     command="validate"

vcell-cli/src/main/java/org/vcell/cli/CLIStandalone.java

@@ -4,6 +4,7 @@
 import org.vcell.cli.run.ExecuteCommand;
 import org.vcell.cli.run.ExecuteOmexCommand;
 import org.vcell.cli.sbml.ModelCommand;
+import org.vcell.cli.testing.TestReportCommand;
 import org.vcell.cli.vcml.*;
 
 import org.apache.logging.log4j.LogManager;
@@ -24,6 +25,7 @@
         ImportOmexCommand.class,
         ImportOmexBatchCommand.class,
         ExecuteOmexCommand.class,
+        TestReportCommand.class,
         ExecuteCommand.class,
         VersionCommand.class,
         ModelCommand.class,

vcell-cli/src/main/java/org/vcell/cli/run/ExecuteCommand.java

@@ -16,7 +16,7 @@
 import java.util.concurrent.Callable;
 import java.util.Date;
 
-@Command(name = "execute", description = "run .vcml or .omex files via Python API")
+@Command(name = "execute", description = "run .vcml or .omex files.")
 public class ExecuteCommand implements Callable<Integer> {
 
     private final static Logger logger = org.apache.logging.log4j.LogManager.getLogger(ExecuteCommand.class);
@@ -39,6 +39,9 @@ public class ExecuteCommand implements Callable<Integer> {
     @Option(names = "--keepFlushingLogs", defaultValue = "false")
     private boolean bKeepFlushingLogs = false;
 
+    @Option(names = "--guaranteeGoodReturnCode", defaultValue = "false", description = "Even on failure, return error code 0 for script purposes.")
+    private boolean bGuaranteeGoodReturnCode = false;
+
     @Option(names = "--small-mesh", defaultValue = "false", description = "force spatial simulations to have a very small mesh to make execution faster")
     private boolean bSmallMeshOverride = false;
 
@@ -100,7 +103,7 @@ public Integer call() {
                     bKeepTempFiles, bExactMatchOnly, bEncapsulateOutput, 
                     EXECUTABLE_MAX_WALLCLOCK_MILLIS, help, bDebug, bQuiet
             );
-            logger.trace(trace_args);
+            logger.debug(trace_args);
 
             logger.debug("Validating CLI arguments");
             if (bDebug && bQuiet) {
@@ -135,7 +138,7 @@ public Integer call() {
             return 0;
         } catch (Exception e) { ///TODO: Break apart into specific exceptions to maximize logging.
             org.apache.logging.log4j.LogManager.getLogger(this.getClass()).error(e.getMessage(), e);
-            return 1;
+            return bGuaranteeGoodReturnCode ? 0 : 1;
         } finally {
             logger.debug("Completed all execution");
         }

vcell-cli/src/main/java/org/vcell/cli/run/ExecuteImpl.java

@@ -135,7 +135,7 @@ public static void singleMode(File inputFile, File rootOutputDir, CLIRecordable
 
         logger.info("Preparing output directory...");
         // we don't want to accidentally delete the input...
-        // if the output is a subset of the input file's housing directory, we shouldn't delete!!
+        // if the output directory is a subset of the input file's housing directory, we shouldn't delete!!
         if (!inputFile.getParentFile().getCanonicalPath().contains(adjustedOutputDir.getCanonicalPath()))
             RunUtils.removeAndMakeDirs(adjustedOutputDir);
 

vcell-cli/src/main/java/org/vcell/cli/run/ExecuteOmexCommand.java

@@ -8,8 +8,8 @@
 import org.vcell.cli.CLIPythonManager;
 import org.vcell.cli.CLIRecordable;
 import org.vcell.cli.CliTracer;
-import org.vcell.cli.testsupport.OmexExecSummary;
-import org.vcell.cli.testsupport.OmexTestingDatabase;
+import org.vcell.sedml.testsupport.OmexExecSummary;
+import org.vcell.sedml.testsupport.OmexTestingDatabase;
 import org.vcell.trace.Tracer;
 import org.vcell.util.FileUtils;
 import org.vcell.util.exe.Executable;
@@ -63,6 +63,7 @@ public class ExecuteOmexCommand implements Callable<Integer> {
     public Integer call() {
 
         CLIRecordable cliTracer = new CliTracer();
+        long startTime_ms = System.currentTimeMillis();
         try {
             if (bDebug && bQuiet) {
                 System.err.println("cannot specify both debug and quiet, try --help for usage");
@@ -106,18 +107,19 @@ public Integer call() {
             FileUtils.copyDirectoryContents(tmpDir, outputFilePath, true, null);
             final OmexExecSummary omexExecSummary;
             if (Tracer.hasErrors()){
-                omexExecSummary = OmexTestingDatabase.summarize(inputFilePath,(Exception)null,Tracer.getErrors());
+                omexExecSummary = OmexTestingDatabase.summarize(inputFilePath,(Exception)null,Tracer.getErrors(), System.currentTimeMillis() - startTime_ms);
             } else {
                 omexExecSummary = new OmexExecSummary();
                 omexExecSummary.file_path = String.valueOf(inputFilePath);
                 omexExecSummary.status = OmexExecSummary.ActualStatus.PASSED;
+                omexExecSummary.elapsed_time_ms = System.currentTimeMillis() - startTime_ms;
             }
             new ObjectMapper().writeValue(new File(outputFilePath, "exec_summary.json"), omexExecSummary);
             new ObjectMapper().writeValue(new File(outputFilePath, "tracer.json"), Tracer.getTraceEvents());
             return 0;
         } catch (Exception e) { ///TODO: Break apart into specific exceptions to maximize logging.
             LogManager.getLogger(this.getClass()).error(e.getMessage(), e);
-            OmexExecSummary omexExecSummary = OmexTestingDatabase.summarize(inputFilePath,e,Tracer.getErrors());
+            OmexExecSummary omexExecSummary = OmexTestingDatabase.summarize(inputFilePath,e,Tracer.getErrors(),System.currentTimeMillis() - startTime_ms);
             try {
                 new ObjectMapper().writeValue(new File(outputFilePath, "exec_summary.json"), omexExecSummary);
                 new ObjectMapper().writeValue(new File(outputFilePath, "tracer.json"), Tracer.getTraceEvents());

vcell-cli/src/main/java/org/vcell/cli/run/SolverHandler.java

@@ -99,7 +99,6 @@ private static void sanityCheck(VCDocument doc) {
     }
 
     public void initialize(List<BioModel> bioModelList, SedML sedml) throws ExpressionException {
-
 		Set <AbstractTask> topmostTasks = new LinkedHashSet<> ();
         for(BioModel bioModel : bioModelList) {
 			Simulation[] sims = bioModel.getSimulations();
@@ -391,12 +390,15 @@ public void simulateAllTasks(ExternalDocInfo externalDocInfo, SedML sedml, CLIRe
 				}
 
 				for (TempSimulationJob tempSimulationJob : simJobsList) {
-					logger.debug("Initializing simulation job... ");
-					String logTaskMessage = "Initializing simulation job " + tempSimulationJob.getJobIndex() + " ... ";
+					AbstractTask task = tempSimulationToTaskMap.get(tempSimulationJob.getTempSimulation());
+					String paramScanIndex = task instanceof RepeatedTask ? ":" + tempSimulationJob.getJobIndex() : "";
+					String tempSimJobLabel = tempSimulationJob.getSimulationJobID() + tempSimulationJob.getJobIndex();
+					String logTaskMessage = String.format("Initializing simulation job %s (%s%s)...", tempSimJobLabel, task.getId(), paramScanIndex);
+					logger.debug(logTaskMessage);
 					String logTaskError = "";
 					long startTimeTask_ms = System.currentTimeMillis();
 
-					AbstractTask task = tempSimulationToTaskMap.get(tempSimulationJob.getTempSimulation());
+
 
 					SimulationTask simTask;
 					String kisao = "null";

vcell-cli/src/main/java/org/vcell/cli/run/hdf5/BiosimulationsHdf5Writer.java

@@ -36,7 +36,7 @@ public static void writeHdf5(HDF5ExecutionResults hdf5ExecutionResults, File out
         boolean didFail = false;
 
         // Create and open the Hdf5 file
-        logger.info("Creating hdf5 file `reports.h5` in" + outDirForCurrentSedml.getAbsolutePath());
+        logger.info("Creating hdf5 file `reports.h5` in {}", outDirForCurrentSedml.getAbsolutePath());
         File tempFile = new File(outDirForCurrentSedml, "reports.h5");
         try {
             try (WritableHdfFile hdf5File = HdfFile.write(tempFile.toPath())){

vcell-cli/src/main/java/org/vcell/cli/run/hdf5/SpatialResultsConverter.java

@@ -43,6 +43,11 @@ public static Map<Report, List<Hdf5SedmlResults>> convertSpatialResultsToSedmlFo
                 BiosimulationLog.instance().updateDatasetStatusYml(sedmlLocation, report.getId(), dataSet.getId(), BiosimulationLog.Status.SUCCEEDED);
             } // end of dataset
 
+            if (dataGenToDataSets.isEmpty()){
+                lg.warn(String.format("Report `%s` does not have any valid spatial component!", report.getId()));
+                continue;
+            }
+
             // Fill out DatasetWrapper Values
             Hdf5SedmlResultsSpatial.SpatialComponents reportMappings = convertedData.dataMapping.get(report);
             Hdf5SedmlResults hdf5DatasetWrapper = new Hdf5SedmlResults();
@@ -89,18 +94,24 @@ private static boolean processDataGenerator(SedML sedml, Report report, DataGene
         Map<AbstractTask, TempSimulation> sedmlTaskToVCellSim = new HashMap<>();
         boolean allVarsValid = true;
         for (Variable variable : dataGenVarList) { // Since we're only doing single variable, this should run once!
-            // Check if it's asking for time (we don't include time with the rest of spatial data).
-            if (variable.isSymbol()) if (VariableSymbol.TIME.equals(variable.getSymbol())) continue;
             // for each variable we recover the task
             AbstractTask completeTask = sedml.getTaskWithId(variable.getReference());
             if (completeTask == null) throw new RuntimeException("Null SedML task encountered");
-            AbstractTask fundamentalTask = SpatialResultsConverter.getBaseTask(completeTask, sedml);
             // from the task we get the sbml model
+            if (!sourceOfTruth.getTaskGroupSet().contains(completeTask.getId())){
+                lg.info(String.format("`%s` is not a spatial task!", completeTask.getId()));
+                allVarsValid = false;
+                continue;
+            }
+            AbstractTask fundamentalTask = SpatialResultsConverter.getBaseTask(completeTask, sedml);
             if (!(sedml.getSimulation(fundamentalTask.getSimulationReference()) instanceof UniformTimeCourse utcSim)){
                 lg.error("only uniform time course simulations are supported");
                 allVarsValid = false;
                 break;
             }
+            // Check if it's asking for time (we don't include time with the rest of spatial data).
+            if (variable.isSymbol()) if (VariableSymbol.TIME.equals(variable.getSymbol())) continue;
+
             sedmlTaskToVCellSim.put(completeTask, completeSedmlTaskToVCellSim.get(completeTask));
         }
         if (allVarsValid){
@@ -159,7 +170,7 @@ private static boolean processDataGenerator(SedML sedml, Report report, DataGene
             if (comps.varsToData == null) comps.varsToData = newVars;
             else comps.varsToData.integrateSimilarLocations(taskVars);
         }
-        return true;
+        return allVarsValid;
     }
 
     private static List<Report> getReports(List<Output> outputs){

vcell-cli/src/main/java/org/vcell/cli/testing/TestReportCommand.java

@@ -0,0 +1,83 @@
+package org.vcell.cli.testing;
+
+import org.apache.logging.log4j.Level;
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
+import org.apache.logging.log4j.core.LoggerContext;
+import org.vcell.sedml.testsupport.OmexExecSummary;
+import org.vcell.sedml.testsupport.OmexTestCase;
+import org.vcell.sedml.testsupport.OmexTestReport;
+import org.vcell.sedml.testsupport.OmexTestingDatabase;
+import picocli.CommandLine.Command;
+import picocli.CommandLine.Option;
+
+import java.io.File;
+import java.nio.file.Files;
+import java.util.List;
+import java.util.concurrent.Callable;
+import java.util.function.Predicate;
+
+@Command(name = "test-report", description = "create test reports for a test suite")
+public class TestReportCommand implements Callable<Integer> {
+
+    private final static Logger logger = LogManager.getLogger(TestReportCommand.class);
+
+    @Option(names = { "-t", "--test-cases" }, required = false, description = "[optional] test cases file - defaults to embedded test cases")
+    private File testCasesNdjsonFile;
+
+    @Option(names = { "-e", "--exec-summaries" }, required = true, description = "test results file e.g. exec_summary.ndjson")
+    private File execSummaryNdjsonFile;
+
+    // list of OmexTestingDatabase.TestCollection objects to include
+    @Option(names = { "-c", "--collections" }, required = true, description = "list of test collections to include")
+    private List<OmexTestingDatabase.TestCollection> collections;
+
+    @Option(names = { "--report-md" }, required = true, description = "filename for generated markdown test report (e.g. ./report.md)")
+    private File reportFile_md;
+
+    @Option(names = { "--report-json" }, required = false, description = "filename for generated json test report (e.g. ./report.json)")
+    private File reportFile_json;
+
+    @Option(names = { "-d", "--debug" }, description = "enable debug logging")
+    private boolean bDebug = false;
+
+    public Integer call() {
+        Level logLevel = bDebug ? Level.DEBUG : logger.getLevel(); 
+
+        LoggerContext config = (LoggerContext)(LogManager.getContext(false));
+        config.getConfiguration().getLoggerConfig(LogManager.getLogger("org.vcell").getName()).setLevel(logLevel);
+        config.getConfiguration().getLoggerConfig(LogManager.getLogger("cbit").getName()).setLevel(logLevel);
+        config.updateLoggers();
+
+        try {
+            // read test cases and filter by collections
+            Predicate<OmexTestCase> omexTestCasePredicate = tc -> collections.contains(tc.test_collection);
+            final List<OmexTestCase> testCaseList;
+            if (testCasesNdjsonFile != null) {
+                String test_cases_contents = Files.readString(testCasesNdjsonFile.toPath());
+                testCaseList = OmexTestingDatabase.parseOmexTestCases(test_cases_contents).stream().filter(omexTestCasePredicate).toList();
+            } else {
+                // if file not specified, use embedded test cases
+                testCaseList = OmexTestingDatabase.loadOmexTestCases().stream().filter(omexTestCasePredicate).toList();
+            }
+
+            // read exec summaries
+            String exec_summary_contents = Files.readString(execSummaryNdjsonFile.toPath());
+            List<OmexExecSummary> execSummaries = OmexTestingDatabase.loadOmexExecSummaries(exec_summary_contents);
+
+            // generate report
+            OmexTestReport report = OmexTestingDatabase.generateReport(testCaseList, execSummaries);
+            if (reportFile_json != null) {
+                Files.writeString(reportFile_json.toPath(), report.toJson());
+            }
+            if (reportFile_md != null) {
+                Files.writeString(reportFile_md.toPath(), report.toMarkdown());
+            }
+            return 0;
+        } catch (Exception e) {
+            throw new RuntimeException(e.getMessage(), e);
+        } finally {
+            logger.debug("Completed all exports");
+        }
+    }
+}