If you can't find the product or version you're looking for, visit support.ataccama.com/downloads

How to Log Workflow Execution

Running a workflow generates logs with the information about the result of workflow execution and behavior of workflow tasks. In the server context, you can configure a single log for all workflows with custom logging settings.

This article covers the information about the logs contents, configuration options, and conditions for generating logs in different execution contexts. For the general logging reference, see Logging Configuration.

If there are syntax and other general configuration errors in the workflow that result in an invalid workflow configuration file, no logs are created when the workflow is started. In the server context (workflows deployed via the Workflow Component), such workflows are marked with ERROR in the ONE Runtime Server Admin and cannot be started at all.

Workflow instance state

A workflow instance state log contains full information about the execution state of all tasks, links, and the entire workflow, as well as the configured variables and global settings. The log can be stored either to a workflow instance state .wis file or to a database.

WIS file

In the batch mode, the workflow state is always stored to a .wis file. In the server context, the workflow state information is stored to a .wis file if State Storage Provider is set to File State Storage Provider in the Workflow Component.

Every workflow execution generates a new .wis file. The file contains information about the current state of the workflow and all included tasks and is updated every time the status of any part of the workflow changes (for example, a task is scheduled or executed).

The following information is included for each server with an executed workflow:

Hostname
IP address
Port

For database storage, the following columns are in the workflow instances table.

host_name
host_address
host_port

In the batch mode, there is no limit on the number of stored logs. To clean the log history, you have to manually delete the logs.

In the server mode, set the EWFHistoryDepth Workflow Runtime Parameters on server startup to set the maximum number of historical log files stored for a workflow.

The name and location of the generated file depend on the configuration and execution context. The following table summarizes the differences.

Execution context Location File name

IDE

The same folder as the workflow.

Overwritten each time, for example, workflow_name.wis, unless a new one is specified in Run Configuration (Workflow Launch tab) each time the workflow is launched.

Batch script

As specified in the command.

If the file is not specified, the state is not logged.

Server

Resources folder specified in Workflow Component.
Fallback 1: Resources folder specified in Runtime Configuration.
Fallback 2: The folder containing Server Configuration.

Serialized with unique ID assigned by the server, with the following naming convention: <wf_source_id>@<workflow_name>.ewf_<inst_id>.wis.

A common source separator character (colon) is replaced with the at sign (@) in the WIS file name because the colon (:) is not supported on some filesystems. Example: wf1@workflow.ewf_6.wis.

Making changes to a workflow and then running it in the server context deletes all historical logs of the original workflow.

For detailed information about the workflow execution options, see Execute Workflows.

The following example shows the contents of a WIS file:

Sample .wis state file

<?xml version='1.0' encoding='UTF-8'?>
<WorkflowInstanceState>
    <hostInfo hostName="MACHINE" hostPort="7777" hostAddress="10.254.253.79"/>
    <forcedResume>false</forcedResume>  <!-- information about current state of the workflow -->
    <id>1</id>
    <linkEvaluations/>
    <started>2017-03-01 13:50:51</started>
    <state>FINISHED_OK</state>
    <stopped>2017-03-01 13:50:51</stopped>
    <taskVariables>
        <taskVariableBean task="001_hello_world" name="SCRIPT_RESULT_CODE" type="INTEGER" value="0"/>
    </taskVariables>
    <tasks>                               <!-- contains current states of tasks -->
        <workflowTaskPersistModelBean stopped="2017-03-01 13:50:51" started="2017-03-01 13:50:51" id="001_hello_world" state="FINISHED_OK">
            <compensationStates/>
        </workflowTaskPersistModelBean>
    </tasks>
    <wfTimestamp>2017-03-01 13:50:46</wfTimestamp>
    <wfVariables>                     <!-- contains values of the variables the workflow was started with -->
        <variableBean name="SALUTATION" type="STRING" value=""/>
        <variableBean name="ewf_execution_id" type="STRING" value="2017-03-01_13-50-51_5101"/>
        <variableBean name="ewf_workflow_id" type="STRING" value="00_01_Hello_World.ewf"/>
        <variableBean name="ewf_private_folder" type="STRING" value="C:\Products\Ataccama-all-11.0.0.ga-2017-02-10-win-x86_64_2\workspace\Workflow Tutorials\00_Introduction\wfinst_2017-03-01_13-50-51_5101"/>
        <variableBean name="ewf_user_name" type="STRING" value=""/>
    </wfVariables>
    <workflowId>00_01_Hello_World.ewf</workflowId>
</WorkflowInstanceState>

Database persistence

When used in the server context (with Workflow Component), the workflow state information can be stored in a database across several tables. In this case, a .wis file is not created. To enable database persistence, set State Storage Provider to Database State Storage Provider.

The workflow state persister registers several tables with the wisp prefix (Workflow Instance State Persister), the following being the most useful ones:

wisp_wf_instance - Contains information about workflow instances. Every workflow execution inserts a row with a unique ID. Other tables use it as a foreign key in the INST_ID column.
wisp_wf_tasks - Contains states of the individual workflow tasks.
wisp_wf_linkeval - Contains states of links between tasks. For more information about wisp tables, see Workflow and Scheduler Database Persistence Tables.

WFINST folder

A wfinst folder contains subfolders with logs of individual tasks and temporary scripts. Each workflow task creates one task.log file. Tasks that initiate other processes (Run DQC Process, Run Shell Script, Run Windows Command) log into two files: stdout.log`and `stderr.log. Every workflow execution generates a new wfinst folder.

In the batch mode, there is no limit on the number of stored wfinst folders. To clean the log history, you have to manually delete the logs.

In the server mode, set the EWFHistoryDepth Workflow Runtime Parameters on server startup to set the maximum number of historical wfinst folders stored for a workflow.

The name and location of the wfinst folders depend on the configuration and execution context. The following table summarizes the differences.

Execution context Location Unique folder per run

IDE

The same folder as the workflow.

Yes, in the datetime form, for example, wfinst_2017-03-13_15-02-03_8501.

Batch script

* Resources folder specified in Runtime Configuration. * Fallback: The same folder as the script that started the workflow, for example, <ATACCAMA_HOME>/bin/runewf.sh.

Yes, in the datetime form, for example, wfinst_2017-03-13_15-02-03_8501.

Server

* Resources folder specified in Workflow Component. * Fallback 1: Resources folder specified in Runtime Configuration. * Fallback 2: The folder containing Server Configuration.

Yes, serialized with unique ID assigned by the server, for example, wfinst_6.

Making changes to a workflow and then running it in the server context deletes all historical logs of the original workflow.

For detailed information about the workflow execution options, see Execute Workflows.

Workflow logging as part of unified server logging

ONE lets you log the behavior of workflows executed in ONE Runtime Server into a single log, together with the other server components. Configuring workflow logging in the server context does not affect the workflow instance state and WFINST outputs described above.

What is logged?

Generally speaking, workflows log two types of activities:

Technical: Synchronization of the source directories that contain workflows and past execution logs. These are logged on the DEBUG level and can be logged to a separate text file for debugging purposes.
Execution: Starting and finishing of workflows and tasks and execution details. These are logged on the INFO level.

The level of detail can be configured in the Workflow Component. For details, see Comparison of log levels.

Prepare custom logging configuration

Update logging configuration

This step is optional.

Review your Logging Configuration and add new logging rules and appenders if necessary. For example, it makes sense to limit the severity level of logs written to the console output to INFO to capture the actual execution logs.

The following excerpt shows a possible configuration to achieve that: logs of the severity level INFO and higher coming from the Workflow Server Component are written to the standard output (console).

Workflow logging configuration excerpt

<?xml version='1.0' encoding='UTF-8'?>
<loggingConfig>
    <appenders>
        ...
        <iLogAppenderFactory logMillis="false" name="console" class="com.ataccama.dqc.commons.logging.factories.StdOutLogAppenderFactory" useStdErr="false"/>
        ...
    </appenders>
    <loggingRules>
        ...
        <loggingRule level="INFO" appender="console">
            <trace>
                <string>WorkflowServerComponent</string>
            </trace>
        </loggingRule>
        ...
    </loggingRules>
</loggingConfig>

Set the log level

The log level setting influences how much detail is logged. Set it in the Workflow Component.

Comparison of log levels

This section provides examples of log records created after the execution of a sample workflow consisting of one Run DQC task that starts a plan with a Record Counter step. Log records of severity level INFO and higher are logged. Note the effect of the Log Level setting on the resulting log.

Log Level 2 logs the starting and finishing of workflows and state changes of workflow tasks.

Sample log, log level 2

09.03.2017 12:17:13 [INFO]    [WorkflowServerComponent][default:workflow.ewf_49] Workflow task Run DQC changed state: IN_QUEUE
09.03.2017 12:17:13 [INFO]    [WorkflowServerComponent][default:workflow.ewf_49] Workflow started executing.
09.03.2017 12:17:13 [INFO]    [WorkflowServerComponent][default:workflow.ewf_49] Workflow task Run DQC changed state: RUNNING
09.03.2017 12:17:13 [INFO]    [WorkflowServerComponent][default:workflow.ewf_49] Workflow task Run DQC changed state: FINISHED_OK
09.03.2017 12:17:13 [INFO]    [WorkflowServerComponent][default:workflow.ewf_49] Workflow finished with state FINISHED_OK.

Log Level 3 logs activities of workflow tasks. This is the maximum log level for most workflows.

Sample log, log level 3

09.03.2017 12:15:49 [INFO]    [WorkflowServerComponent][default:workflow.ewf_48] Workflow task Run DQC changed state: IN_QUEUE
09.03.2017 12:15:49 [INFO]    [WorkflowServerComponent][default:workflow.ewf_48] Workflow started executing.
09.03.2017 12:15:49 [INFO]    [WorkflowServerComponent][default:workflow.ewf_48] Workflow task Run DQC changed state: RUNNING
09.03.2017 12:15:49 [INFO]    [WorkflowServerComponent][default:workflow.ewf_48][Run DQC] Validating model...
09.03.2017 12:15:49 [INFO]    [WorkflowServerComponent][default:workflow.ewf_48][Run DQC] Creating runtime...
09.03.2017 12:15:49 [INFO]    [WorkflowServerComponent][default:workflow.ewf_48][Run DQC] Running runtime...
09.03.2017 12:15:49 [INFO]    [WorkflowServerComponent][default:workflow.ewf_48][Run DQC] Finished! (Time spent: 0 s)
09.03.2017 12:15:49 [INFO]    [WorkflowServerComponent][default:workflow.ewf_48] Workflow task Run DQC changed state: FINISHED_OK
09.03.2017 12:15:49 [INFO]    [WorkflowServerComponent][default:workflow.ewf_48] Workflow finished with state FINISHED_OK.

Log Level 4 logs activities of other tasks started by workflows. In this example, it logs activities of the Record Counter step.

Log Level -1 logs everything. In this example, it generates the same log as Level 4 (which is the maximum level at which this workflow logs).

Sample log, log level 4, -1

09.03.2017 12:13:02 [INFO]    [WorkflowServerComponent][default:workflow.ewf_47] Workflow task Run DQC changed state: IN_QUEUE
09.03.2017 12:13:02 [INFO]    [WorkflowServerComponent][default:workflow.ewf_47] Workflow started executing.
09.03.2017 12:13:02 [INFO]    [WorkflowServerComponent][default:workflow.ewf_47] Workflow task Run DQC changed state: RUNNING
09.03.2017 12:13:02 [INFO]    [WorkflowServerComponent][default:workflow.ewf_47][Run DQC] Validating model...
09.03.2017 12:13:02 [INFO]    [WorkflowServerComponent][default:workflow.ewf_47][Run DQC] Creating runtime...
09.03.2017 12:13:02 [INFO]    [WorkflowServerComponent][default:workflow.ewf_47][Run DQC] Running runtime...
09.03.2017 12:13:02 [INFO]    [WorkflowServerComponent][default:workflow.ewf_47][Run DQC][Record Counter] Processing started.
09.03.2017 12:13:02 [INFO]    [WorkflowServerComponent][default:workflow.ewf_47][Run DQC][Record Counter] 10 recs 10000 recs/s
09.03.2017 12:13:02 [INFO]    [WorkflowServerComponent][default:workflow.ewf_47][Run DQC][Record Counter] 20 recs 10000 recs/s
09.03.2017 12:13:02 [INFO]    [WorkflowServerComponent][default:workflow.ewf_47][Run DQC][Record Counter] 30 recs N/A
09.03.2017 12:13:02 [INFO]    [WorkflowServerComponent][default:workflow.ewf_47][Run DQC][Record Counter] 40 recs N/A
09.03.2017 12:13:02 [INFO]    [WorkflowServerComponent][default:workflow.ewf_47][Run DQC][Record Counter] 50 recs N/A
09.03.2017 12:13:02 [INFO]    [WorkflowServerComponent][default:workflow.ewf_47][Run DQC][Record Counter] 60 recs N/A
09.03.2017 12:13:02 [INFO]    [WorkflowServerComponent][default:workflow.ewf_47][Run DQC][Record Counter] 70 recs N/A
09.03.2017 12:13:02 [INFO]    [WorkflowServerComponent][default:workflow.ewf_47][Run DQC][Record Counter] 80 recs N/A
09.03.2017 12:13:02 [INFO]    [WorkflowServerComponent][default:workflow.ewf_47][Run DQC][Record Counter] 90 recs N/A
09.03.2017 12:13:02 [INFO]    [WorkflowServerComponent][default:workflow.ewf_47][Run DQC][Record Counter] 100 recs 10000 recs/s
09.03.2017 12:13:02 [INFO]    [WorkflowServerComponent][default:workflow.ewf_47][Run DQC][Record Counter] Processing finished. 20000 recs/s
09.03.2017 12:13:02 [INFO]    [WorkflowServerComponent][default:workflow.ewf_47][Run DQC] Finished! (Time spent: 0 s)
09.03.2017 12:13:02 [INFO]    [WorkflowServerComponent][default:workflow.ewf_47] Workflow task Run DQC changed state: FINISHED_OK
09.03.2017 12:13:02 [INFO]    [WorkflowServerComponent][default:workflow.ewf_47] Workflow finished with state FINISHED_OK.

Was this page useful?