Introduction

JS7 does not make use of files for log output of order logs and task logs, see the JS7 - Order Logs and Task Logs article for detailed information. Instead, JS7

Introduction

JS7 does not make use of files for log output of order logs and task logs.

• Files are a frequent source of error as they might not be created due to restrictions of disk space or permissions.
• If a log file cannot be created then this could block processing of jobs. Even worse, if log files are not available then users are blind about job execution results.

JS7 therefore streams log output from Agents to the Controller and to the JOC Cockpit without the use of files.

• Streaming makes job log output available to JOC Cockpit within 1s. 
• Streaming allows a running log which translates to the fact that users observe ongoing log output of orders and jobs in the log view window.
• In case of missing connections
  • between Controller and Agent then the Agent stores log output in its journal and forwards logs when reconnected to a Controller later on. 
  • between JOC Cockpit and Controller then the Controller stores log output in its journal and forwards logs when reconnected to JOC Cockpit later on.

Scope

A number of users prefer to have log files available for each order execution and job execution, for example to consolidate log files on a file server or to submit log files to specific tools for log analysis.

• Log analysis is useful but usually comes too late. It's more a reporting activity that is not intended to replace near-real time monitoring.
• Log analysis starts when the log is completed.
• Log analysis is useful when it comes to parsing logs for unexpected output or errors. However, it might prove tedious to teach a log analyzer recovery of errors from log output in case that a job was successfully restarted for a specific order.

To support a situation when log output should be consolidated or should be analyzed by external tools the JS7 - REST Web Service API allows access to log output of orders and jobs.

The JS7 - PowerShell Module is a lightweight wrapper for the REST Web Service API that is used for the below examples.

Order Logs

Order logs include the task log output of each job included in a workflow. This provides better context that use of individual task logs.

The following cmdlets are provided:

• Get-JS7OrderHistory
• Get-JS7OrderLog

Access Order Log Object

A number of users prefer to have log files available for each order execution and job execution, for example to consolidate log files on a file server or to submit log files to specific tools for log analysis.

To support a situation when log output should be consolidated to files, the JS7 - REST Web Service API allows access to log output of orders and jobs. The JS7 - PowerShell Module is a lightweight wrapper for the REST Web Service API that is used for the examples below on Linux and Windows. Users are free to use the JS7 REST Web Service from their preferred scripting language to provide similar functionality.

Task logs can be handled similarly - see JS7 - How to make task logs available from files.

Order Logs

Order logs include the task log output of each job and instructions included in a workflow. This provides better a context than the use of individual task logs.

The following cmdlets are provided:

• Get-JS7OrderHistory
• Get-JS7OrderLog

Access Log Object

$logs = Get-JS7OrderHistory | Get-JS7OrderLog

Explanation:

• The Get-JS7OrderHistory cmdlet returns history results that can be filtered by folders, workflows, date range, order states, see cmdlet description linked above. By default today's order executions are returned.
• The Get-JS7OrderLog cmdlet is used in a pipeline and returns the order log object for each history entry.
• As a result the $logs array holds the list of order log objects.

An order log object carries a number of attributes as can be seen in the following console example:

PS /> $logs = Get-JS7OrderHistory | Get-JS7OrderLog

Explanation:

• The Get-JS7OrderHistory cmdlet returns history results that can be filtered by folders, workflows, date range, order states etc. By default today's order executions are returned.
• The Get-JS7OrderLog cmdlet is used in a pipeline and returns the order log for each history entry.
• As a result the $logs array holds the list of order logs.

...

PS > $logs = Get-JS7OrderHistory | Get-JS7OrderLog
PS > $logs[0]

controllerId : jobscheduler
historyId    : 3092
orderId      : #2022-03-06#P31960623406-cycle2
workflow     : /Examples.Windows/05_ScheduledExecution/jdwScheduledWorkflowCyclic
position     :
state        : 
PS /> $logs[0]

controllerId : jobscheduler
historyId    : 3092
orderId      : #2022-03-06#P31960623406-cycle2
workflow     : /Examples.Windows/05_ScheduledExecution/jdwScheduledWorkflowCyclic
position     :
state        : @{severity=6; _text=SUCCESSFUL}
plannedTime  : 06.03.2022 09:12:00
startTime    : 06.03.2022 09:12:05
endTime      : 06.03.2022 09:12:32
log          : 2022-03-06 09:12:05.265+0100 [MAIN]    [OrderStarted]   id=#2022-03-06#P31960623406-cycle2, pos=0
               2022-03-06 09:12:05.377+0100 [MAIN]    [OrderProcessingStarted] id=#2022-03-06#P31960623406-cycle2, pos=0, Job=job1, Agent (url=https://apmacwin:4245,
               id=agent_001, time=2022-03-06 09:12:05.265+0100)

               2022-03-06 09:12:05.265+0100 [MAIN]    [Start] Job=job1, Agent (url=https://apmacwin:4245, id=agent_001)
               2022-03-06 09:12:05.955+0100 [STDOUT]  using workflow: jdwScheduledWorkflowCyclic
               running job1
               order scheduler for: 2022-03-06 08:12:00+0000
               job start date: 2022-03-06 08:12:05+0000
               2022-03-06 09:12:10.653+0100 [MAIN]    [End] [Success] returnCode=0

               2022-03-06 09:12:10.753+0100 [SUCCESS] [OrderProcessed] id=#2022-03-06#P31960623406-cycle2, pos=0, Job=job1, returnCode=0
               2022-03-06 09:12:10.669+0100 [DETAIL]  [OrderForked]    id=#2022-03-06#P31960623406-cycle2, pos=1
               2022-03-06 09:12:10.669+0100 [DETAIL]  [OrderStarted]   id=#2022-03-06#P31960623406-cycle2|branch1, pos=1/branch1:0
               2022-03-06 09:12:10.669+0100 [DETAIL]  [OrderStarted]   id=#2022-03-06#P31960623406-cycle2|branch2, pos=1/branch2:0
               2022-03-06 09:12:10.753+0100 [MAIN]    [OrderProcessingStarted] id=#2022-03-06#P31960623406-cycle2|branch1, pos=1/fork+branch1:0, Job=job2_1a, Agent
               (url=https://apmacwin:4245, id=agent_001, time=2022-03-06 09:12:10.669+0100)

               2022-03-06 09:12:10.669+0100 [MAIN]    [Start] Job=job2_1a, Agent (url=https://apmacwin:4245, id=agent_001)
               2022-03-06 09:12:11.306+0100 [STDOUT]  using workflow: jdwScheduledWorkflowCyclic
               running job2_1a
               order scheduler for: 2022-03-06 08:12:00+0000
               job start date: 2022-03-06 08:12:10+0000
               2022-03-06 09:12:16.098+0100 [MAIN]    [End] [Success] returnCode=0

Write

...

Log to File

Get-JS7OrderHistory | Get-JS7OrderLog | Out-File /tmp/history/orders.log -Encoding Unicode

...

Get-JS7OrderHistory -RelativeDateFrom -8h | Get-JS7OrderLog | Select-Object @{name='path'; expression={ "/tmp/history/$(Get-Date $_.startTime -f 'yyyyMMdd-hhmmss')-$([io.path]::GetFileNameWithoutExtension($_.workflow))-$($_.orderId).order.log"}}, @{name='value'; expression={ $_.log }} | Set-Content

...

• Reads the logs of orders that completed within the last 8 hours and writes the log output to individual files in the /tmp directory.

• The log file names are created from the start time, the workflow name and Order ID.

...

# execute once
$lastHistory = Get-JS7OrderHistory -RelativeDateFrom -8h | Sort-Object -Property startTime

# execute in intervals
Get-JS7OrderHistory -DateFrom $lastHistory[0].startTime | Tee-Object -Variable lastHistory | Get-JS7OrderLog | Select-Object @{name='path'; expression={ "/tmp/history/$(Get-Date $_.startTime -f 'yyyyMMdd-hhmmss')-$([io.path]::GetFileNameWithoutExtension($_.workflow))-$($_.orderId).order.log"}}, @{name='value'; expression={ $_.log }} | Set-Content

...

• Provides a mechanism to subsequently retrieve previous logs. Starting from initial execution of the Get-JS7OrderHistory cmdlet the resulting $lastHistory object is used for any subsequent calls.
  Consider use of the Tee-Object cmdlet in the pipeline that updates the $lastHistory object that which can be used for later executions of the same pipeline.

• This pipeline can e.g. , for example, be executed in a cyclic job.

Automate Log File Creation

Task Logs

The following cmdlets are provided:

• Get-JS7TaskHistory
• Get-JS7TaskLog

Access Task Log Object

$logs = Get-JS7TaskHistory | Get-JS7TaskLog

Explanation:

• The Get-JS7TaskHistory cmdlet returns history results that can be filtered by folders, workflows, date range, jobs, see cmdlet description. By default today's task executions are returned.
• The Get-JS7TaskLog cmdlet is used in a pipeline and returns the task log object for each history entry.
• As a result the $logs array holds the list of task log objects.

A workflow is created that runs the commands mentioned above in a cycle. The workflow operates 24/7 and writes order logs to files.

Download (.json upload): pdwOrderLogsToFiles.workflow.json

Image Added

Explanation:

• The first job get-history-order-logs is executed at the point in time when the order which starts the workflow arrives.
  • This job determines the last history entry from which to start.
• The second job write-order-logs-to-files is executed within a JS7 - Cycle Instruction:
  • The above example implements a ticking cycle every 30 minutes. For a 24h period the job will repeat every 30 minutes. 
  • Users can adjust the cycle as required.

The first job get-history-order-logs looks like thisA task log object holds the following elements:

PS > $logs = Get-JS7TaskHistory | Get-JS7TaskLog
PS > $logs[0]

controllerId : jobscheduler
agentUrl     : http://apmaccs:4449
taskId       : 15247
orderId      : #2022-03-06#P31960629618-pdCyclicSimpleWorkflowTicking
workflow     : /ProductDemo/CyclicExecution/pdCyclicSimpleWorkflowTicking
position     : 0/cycle+end=1646607600000,scheme=1,i=10,next=1646564721361:2
job          : job3
criticality  : normal
exitCode     : 0
state        : @{severity=6; _text=SUCCESSFUL}
startTime    : 06.03.2022 12:05:31
endTime      : 06.03.2022 12:05:36
log          : 2022-03-06 12:05:31.388+0100 [MAIN]    [Start] Job=job3, Agent (url=http://apmaccs:4449, id=agent_002)
               2022-03-06 12:05:31.795+0100 [STDOUT]  using workflow: pdCyclicSimpleWorkflowTicking
               running job: job3
               2022-03-06 12:05:36.399+0100 [MAIN]    [End] [Success] returnCode=0

Write Task Log to File

Get-JS7TaskHistory | Get-JS7TaskLog | Out-File /tmp/history/tasks.log -Encoding Unicode

Explanation:

• Reads the logs of today's tasks and writes the logs to a common file.

#!/usr/bin/env pwsh

Import-Module JS7
Connect-JS7 -Url http://root:root@localhost:4446 -Id Controller | Out-Null

$lastHistory = Get-JS7OrderHistory -RelativeDateFrom -30m | Sort-Object -Property startTime

    # forward a variable for the object
    "lastHistory=json:$($lastHistory | ConvertTo-Json -Compress)" | Out-File $env:JS7_RETURN_VALUES -Append

Disconnect-JS7

Explanation:

• Line 1: The shebang is required to identify PowerShell as the interpreter of the script. The above example is for Unix, for Windows the first line of the job script should be replaced as follows:

  • Code Block
    language powershell title Example of shebang for PowerShell with Unix linenumbers true
    #!/usr/bin/env pwsh

  • Code Block
    language powershell title Example of shebang for PowerShell with Windows linenumbers true
    @@findstr/v "^@@f.*&" "%~f0"|pwsh.exe -&goto:eof

• Line 4: The are a number of ways of specifying the details for a JS7 connection - see the JS7 - How to connect to JOC Cockpit using the PowerShell Module article.
  • The host and port are specific for a user's environment.
  • The Controller ID is specified during installation of the Controller and defaults to Controller.
• Line 9: A workflow variable is created that carries the list of order log objects returned by the Get-JS7OrderHistory cmdlet which task logs should be created for. This variable is in fact a PowerShell object that is serialized to JSON and prefixed with the string json: for later use with the second job in the workflow.

The second job write-order-logs-to-files looks like this:

#!/usr/bin/env pwsh

Import-Module JS7
Connect-JS7 -Url http://root:root@localhost:4446 -Id Controller | Out-Null

    # restore object from json by a temporary file
    $lastHistory = ( (Get-Content $env:LAST_HISTORY_FILE).Substring(5) | ConvertFrom-Json )

Get-JS7OrderHistory -DateFrom $lastHistory[0].startTime | Tee-Object -Variable lastHistory | Get-JS7OrderLog

Get-JS7TaskHistory -RelativeDateFrom -8h | Get-JS7TaskLog | Select-Object @{name='path'; expression={ "/tmp/history/$(Get-Date $_.startTime -f 'yyyyMMdd-hhmmss')-$([io.path]::GetFileNameWithoutExtension($_.job)).log"}}, @{name='value'; expression={ $_.log }} | Set-Content

Explanation:

• Reads the logs of tasks that completed within the last 8 hours and writes the log output to individual files. The log file names are created from the start time and from the job name of each task.

# execute once
$lastHistory = Get-JS7TaskHistory -RelativeDateFrom -8h | Sort-Object -Property startTime

# execute in intervals
Get-JS7TaskHistory -DateFrom $lastHistory[0].startTime | Tee-Object -Variable lastHistory | Get-JS7TaskLog | Select-Object @{name='path'; expression={ "/tmp/history/$(Get-Date $_.startTime -f 'yyyyMMdd-hhmmss')-$([io.path]::GetFileNameWithoutExtension($_.job)).log"}}, @{name='value'; expression={ $_.log }} | Set-Content

Explanation:

• Provides a mechanism to subsequently retrieve previous logs. Starting from initial execution of the Get-JS7TaskHistory cmdlet the resulting $lastHistory object is used for any subsequent calls.
  Consider use of the Tee-Object cmdlet in the pipeline that updates the $lastHistory object that can be used for later executions of the same pipeline.

• This pipeline can e.g. be executed in a cyclic job.

...

workflow))-$($_.orderId).order.log"}}, @{name='value'; expression={ $_.log }} | Set-Content

    # forward a variable for the object
    "lastHistory=json:$($lastHistory | ConvertTo-Json -Compress)" | Out-File $env:JS7_RETURN_VALUES -Append

Disconnect-JS7

Explanation:

• Lines 1, 4: The same explanations apply as for the previous job.
• Lines 7: The variable holding the list of order log objects of the last processing of this job is restored from a temporary file which holds the JSON representation of the objects. The temporary files are provided by the JS7 Agent and are referenced from an environment variable which is assigned the workflow variable like this.
  • Image Added
    
    

• Line 10: When reading the order history, the variable carrying the list of order log objects is updated and  forwarded to the workflow for next execution of the cycle.