From be2aaaf2a81948f251317bf9c2d073188b85528f Mon Sep 17 00:00:00 2001 From: James Wood Date: Thu, 1 Sep 2022 09:55:38 -0700 Subject: [PATCH 1/3] Cleaned up cmdline log messages --- .../jpl/cws/engine/CwsExternalTaskThread.java | 43 ++++++------------- 1 file changed, 14 insertions(+), 29 deletions(-) diff --git a/cws-engine-service/src/main/java/jpl/cws/engine/CwsExternalTaskThread.java b/cws-engine-service/src/main/java/jpl/cws/engine/CwsExternalTaskThread.java index 07a066e1..43cd9ba9 100644 --- a/cws-engine-service/src/main/java/jpl/cws/engine/CwsExternalTaskThread.java +++ b/cws-engine-service/src/main/java/jpl/cws/engine/CwsExternalTaskThread.java @@ -115,7 +115,7 @@ public void run() { String msg = "Unknown or uncaught error occured! Details: " + t.getMessage(); - log.error("runTask: Error: " + msg, t); + log.error("Error: " + msg, t); // Create an incident handleCamundaApiCall(Resolution.HANDLE_FAILURE, task.getId(), msg, t.toString(), 0, 0L); @@ -132,9 +132,6 @@ private void runTask() { log.setProcDefKey(task.getProcessDefinitionKey()); log.setActivityInstanceId(task.getActivityInstanceId()); - log.debug("runTask: Running external task for procInstId = " + task.getProcessInstanceId() + ", taskId = " + task.getId() + ", activityId = " + task.getActivityId() + - ", executionId = " + task.getExecutionId() + ", with topic = " + task.getTopicName() + ", task priority = " + task.getPriority() + "..."); - CmdLineInputFields cmdInputFields = new CmdLineInputFields(); CmdLineOutputFields cmdOutputFields = new CmdLineOutputFields(); @@ -176,10 +173,6 @@ private void runTask() { exitCodeEventsMap.put(keyVal[0], keyVal[1]); } - - String msg = "Gathering inputs for ProcInstId \"" + task.getProcessInstanceId() + "\": " + jsonNode.toString(); - - log.debug("runTask: " + msg); } } catch (Throwable t) { @@ -196,7 +189,7 @@ private void runTask() { variableLookupRetries = Integer.parseInt((String)task.getVariables().get(fieldName)); } - log.warn("runTask: Error: Failed to retrieve input variables from execution listener. " + variableLookupRetries + " retries remaining."); + log.warn("Error: Failed to retrieve input variables from execution listener. " + variableLookupRetries + " retries remaining."); if (variableLookupRetries > 0) { @@ -220,7 +213,7 @@ private void runTask() { // variables to never get set. An incident can now be reasonably thrown. String msg = "Failed to retrieve and/or parse input variables. Details: " + t.getMessage(); - log.error("runTask: Error: " + msg, t); + log.error("Error: " + msg, t); // Create an incident handleCamundaApiCall(Resolution.HANDLE_FAILURE, task.getId(), msg, t.toString(), 0, 0L); @@ -237,10 +230,10 @@ private void runTask() { boolean success = executeTask(cmdInputFields, cmdOutputFields); if (success) { - log.debug("runTask: External task completed successfully!"); + log.debug("CmdLine Task completed successfully!"); } else { - log.debug("runTask: External task completed unsuccessfully."); + log.debug("CmdLine Task completed unsuccessfully."); } handleCamundaApiCall(Resolution.COMPLETE, task.getId(), "", "", 0, 0L); @@ -253,7 +246,7 @@ private void runTask() { if (taskRetries > 0) { - log.warn("runTask: handleFailure: (BpmnError: " + e.getMessage() + ") (retries remaining: " + taskRetries + ") (retrying in: " + cmdInputFields.retryDelay + "ms)", e); + log.warn("handleFailure: (BpmnError: " + e.getMessage() + ") (retries remaining: " + taskRetries + ") (retrying in: " + cmdInputFields.retryDelay + "ms)", e); // Do retry handleCamundaApiCall(Resolution.HANDLE_FAILURE, task.getId(), "Retrying...", e.toString(), taskRetries, cmdInputFields.retryDelay); @@ -267,7 +260,7 @@ private void runTask() { int taskRetries = getAndIncrementRetriesForTask(task, cmdInputFields.retries); - log.error("runTask: Error: Optimistic locking exception occurred! Retrying this job.", e); + log.error("Error: Optimistic locking exception occurred! Retrying this job.", e); // Since OptimisticLockingException is recoverable, wait a short while then retry this external task. handleCamundaApiCall(Resolution.HANDLE_FAILURE, task.getId(), "Retrying due to OptimisticLockingException...", e.toString(), taskRetries, PROCESS_ENGINE_ERROR_RETRY_DELAY); @@ -277,7 +270,7 @@ private void runTask() { int taskRetries = getAndIncrementRetriesForTask(task, cmdInputFields.retries); - log.error("runTask: Error: Foreign key exception occurred! Retrying this job.", e); + log.error("Error: Foreign key exception occurred! Retrying this job.", e); // Since Foreign Key Exception is recoverable, wait a short while then retry this external task. handleCamundaApiCall(Resolution.HANDLE_FAILURE, task.getId(), "Retrying due to Foreign Key Exception...", e.toString(), taskRetries, PROCESS_ENGINE_ERROR_RETRY_DELAY); @@ -287,7 +280,7 @@ private void runTask() { int taskRetries = getAndIncrementRetriesForTask(task, cmdInputFields.retries); - log.error("runTask: Error: Process engine exception occurred! Retrying this job. Caused by: " + e.getClass().getCanonicalName(), e); + log.error("Error: Process engine exception occurred! Retrying this job. Caused by: " + e.getClass().getCanonicalName(), e); String msg = "Retrying job due to process engine exception of type " + e.getClass().getCanonicalName(); @@ -298,7 +291,7 @@ private void runTask() { String msg = "Failed to complete task. Details: " + t.getMessage(); - log.error("runTask: Error: " + msg, t); + log.error("Error: " + msg, t); // Create an incident handleCamundaApiCall(Resolution.HANDLE_FAILURE, task.getId(), msg, t.toString(), 0, 0L); @@ -380,7 +373,7 @@ private void handleCamundaApiCall(Resolution resolution, String taskId, String m // Keep going, as this is likely a recoverable error tries--; - log.warn("runTask: Error: Failed Camunda API call " + resolution.toString() + " with exception: " + e.getClass().getCanonicalName()); + log.warn("Error: Failed Camunda API call " + resolution.toString() + " with exception: " + e.getClass().getCanonicalName()); } } @@ -388,7 +381,7 @@ private void handleCamundaApiCall(Resolution resolution, String taskId, String m if (tries <= 0) { String errMsg = "Tried " + resolution.toString() + " but failed after 50 attempts. " + msg; - log.error("runTask: Error: " + errMsg, e); + log.error("Error: " + errMsg, e); // Create an incident externalTaskService.handleFailure(taskId, workerId, errMsg, e.toString(), 0, 0L); @@ -562,7 +555,6 @@ private Boolean executeTask(CmdLineInputFields cmdInputFields, CmdLineOutputFiel // Execute and wait for the process to complete // - log.info("About to execute '" + cmdLine + "'"); long t0 = System.currentTimeMillis(); executor.execute(cmdLine, env, resultHandler); resultHandler.waitFor(); @@ -571,8 +563,8 @@ private Boolean executeTask(CmdLineInputFields cmdInputFields, CmdLineOutputFiel // Get the exit value, log it, and put it in return map // int exitValue = resultHandler.getExitValue(); - log.info("Command '" + cmdInputFields.command + "' exit code:" + exitValue + ". Ran in: " + (t1 - t0) + " ms."); - + log.info("Command '" + cmdInputFields.command + "' exit code: " + exitValue + "\nRan in " + (t1 - t0) + " ms."); + // putting redundant names here on purpose to reduce operator error setOutputVariable("exitValue", exitValue + ""); setOutputVariable("exitCode", exitValue + ""); @@ -636,13 +628,6 @@ private Boolean executeTask(CmdLineInputFields cmdInputFields, CmdLineOutputFiel setOutputVariable("stderr", stderrStr); cmdOutputFields.stderr = stderrStr; - // Log outputs - if (cmdOutputFields.event != null) { - log.info("Command '" + cmdInputFields.command + "' event: " + cmdOutputFields.event); - } - log.info("Command '" + cmdInputFields.command + "' stdout: " + cmdOutputFields.stdout); - log.info("Command '" + cmdInputFields.command + "' stderr: " + cmdOutputFields.stderr); - setStdOutVariables(stdOutLines); //log.debug("-------- TASK TIME = " +(System.currentTimeMillis()-t0) + " --------------"); From ae143b98b876d65114103e12777f18eb310d50a7 Mon Sep 17 00:00:00 2001 From: James Wood Date: Thu, 1 Sep 2022 11:30:30 -0700 Subject: [PATCH 2/3] Changed Cmdline output so need to update test --- cws-test/src/test/java/jpl/cws/test/WebTestIT.java | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/cws-test/src/test/java/jpl/cws/test/WebTestIT.java b/cws-test/src/test/java/jpl/cws/test/WebTestIT.java index ee37356e..f204bec5 100644 --- a/cws-test/src/test/java/jpl/cws/test/WebTestIT.java +++ b/cws-test/src/test/java/jpl/cws/test/WebTestIT.java @@ -314,8 +314,7 @@ public void runHelloWorldTest() { findOnPage("ls"); findOnPage("Hello World"); - findOnPage("Command 'ls' exit code:0"); - findOnPage("Command 'ls' event: success"); + findOnPage("Command 'ls' exit code: 0"); sleep(9000); From 162ac7ee27b4f77b24d2c69ff875d1f58d0b3f3c Mon Sep 17 00:00:00 2001 From: James Wood Date: Thu, 1 Sep 2022 12:34:04 -0700 Subject: [PATCH 3/3] More log cleanup Fixed tests --- .../src/main/java/jpl/cws/task/CmdLineExecTask.java | 12 ++---------- .../jpl/cws/test/integration/ui/HistoryTestIT.java | 6 +++--- .../java/jpl/cws/test/integration/ui/LogsTestIT.java | 4 ++-- 3 files changed, 7 insertions(+), 15 deletions(-) diff --git a/cws-tasks/src/main/java/jpl/cws/task/CmdLineExecTask.java b/cws-tasks/src/main/java/jpl/cws/task/CmdLineExecTask.java index 907ab77f..eaafd55d 100644 --- a/cws-tasks/src/main/java/jpl/cws/task/CmdLineExecTask.java +++ b/cws-tasks/src/main/java/jpl/cws/task/CmdLineExecTask.java @@ -125,7 +125,7 @@ public void executeTask() { log.trace("Added token: " + token); cmdLine.addArgument(token, false); } - log.debug("parsed command: '" + cmdLineString + "' into: " + cmdLine); + log.debug("Parsed command: '" + cmdLineString + "' into: " + cmdLine); DefaultExecuteResultHandler resultHandler = new DefaultExecuteResultHandler(); @@ -168,7 +168,6 @@ public void executeTask() { // Execute and wait for the process to complete // - log.info("About to execute '" + cmdLine + "'"); long t0 = System.currentTimeMillis(); executor.execute(cmdLine, env, resultHandler); resultHandler.waitFor(); @@ -177,7 +176,7 @@ public void executeTask() { // Get the exit value, log it, and put it in return map // int exitValue = resultHandler.getExitValue(); - log.info("Command '" + cmdLineString + "' exit value:" + exitValue + ". Ran in: " + (t1 - t0) + " ms."); + log.info("Command '" + cmdLineString + "' exit value: " + exitValue + "\nRan in: " + (t1 - t0) + " ms."); CmdLineOutputFields cmdOutputFields = new CmdLineOutputFields(); @@ -243,13 +242,6 @@ public void executeTask() { setOutputVariable("stderr", stderrStr); cmdOutputFields.stderr = stderrStr; - // Log outputs - if (cmdOutputFields.event != null) { - log.info("Command '" + cmdLine + "' event: " + cmdOutputFields.event); - } - log.info("Command '" + cmdLine + "' stdout: " + cmdOutputFields.stdout); - log.info("Command '" + cmdLine + "' stderr: " + cmdOutputFields.stderr); - setStdOutVariables(stdOutLines); //log.debug("-------- TASK TIME = " +(System.currentTimeMillis()-t0) + " --------------"); diff --git a/cws-test/src/test/java/jpl/cws/test/integration/ui/HistoryTestIT.java b/cws-test/src/test/java/jpl/cws/test/integration/ui/HistoryTestIT.java index 709eaee2..d0135312 100644 --- a/cws-test/src/test/java/jpl/cws/test/integration/ui/HistoryTestIT.java +++ b/cws-test/src/test/java/jpl/cws/test/integration/ui/HistoryTestIT.java @@ -84,10 +84,10 @@ public void runResultsTest() throws IOException { findOnPage("CWS - History"); if (findOnPage("History Page") - && findOnPage("Command 'mkdir Test' exit code:0.") - && findOnPage("Command 'ls' exit code:0.") + && findOnPage("Command 'mkdir Test' exit code: 0") + && findOnPage("Command 'ls' exit code: 0") && findOnPage("LINE: Test") - && findOnPage("Command 'rmdir Test' exit code:0.")) { + && findOnPage("Command 'rmdir Test' exit code: 0")) { scriptPass = true; testCasesCompleted++; } diff --git a/cws-test/src/test/java/jpl/cws/test/integration/ui/LogsTestIT.java b/cws-test/src/test/java/jpl/cws/test/integration/ui/LogsTestIT.java index cbb99785..b9b2ec78 100644 --- a/cws-test/src/test/java/jpl/cws/test/integration/ui/LogsTestIT.java +++ b/cws-test/src/test/java/jpl/cws/test/integration/ui/LogsTestIT.java @@ -68,10 +68,10 @@ public void runOutputTest() throws IOException { goToPage("logs"); - log.info("Looking for text, 'Graphite', 'Command ls exit exit code:0', and 'Deployed process definitions: test_logs_page.bpmn'."); + log.info("Looking for text, 'Graphite', 'Command ls exit exit code: 0', and 'Deployed process definitions: test_logs_page.bpmn'."); if (findOnPage("Graphite") - && findOnPage("Command 'ls' exit code:0.") + && findOnPage("Command 'ls' exit code: 0") && findOnPage("Deployed process definition: 'test_logs_page.bpmn'")) { scriptPass = true; testCasesCompleted++;