Monitoring processes with their logs

Introduction

When a request incomes into Petals ESB through a service invocation on a binding component, it fires several other service invocations. All these service invocations form a flows or a process. Petals ESB provides a mechanism to rebuild these flows or processes executed from an entry point.

This mechanism is based on standard logs. Traces are logged on each input/output of services that are the flow/process steps.

Contributors
No contributors found for: authors on selected page(s)

An example

According to the following flow/process:

We can get following traces:

# The input/output trace logged
01
... traceCode = 'consumeFlowStepBegin', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = '1aakflk333-sdflkj-5854', flowInterfaceName = '{http://petals.com/bpel/UC1/}UseCase1', flowServiceName = '{http://petals.com/bpel/UC1/}UseCase1Service', flowOperationName = '{http://petals.com/bpel/UC1/}process', client = '127.0.0.1', requestedURL = 'http://192.168.1.140:8080/petals/services/EchoSOAPBinding/'
02
... traceCode = 'consumeFlowStepEnd', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = '1aakflk333-sdflkj-5854'
03
... traceCode = 'consumeFlowStepBegin', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = '1aakflk333-sdflkj-5854',  flowInterfaceName = '{http://petals.com/bpel/UC1/}UseCase1', flowServiceName = '{http://petals.com/bpel/UC1/}UseCase1Service', flowOperationName = '{http://petals.com/bpel/UC1/}process', URLMailboxFolder = 'pop://user@pop.host.com:110/INBOX'
04
... traceCode = 'consumeFlowStepEnd', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = '1aakflk333-sdflkj-5854'
05
... traceCode = 'consumeFlowStepBegin', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = '1aakflk333-sdflkj-5854', flowInterfaceName = '{http://petals.com/bpel/UC1/}UseCase1', flowServiceName = '{http://petals.com/bpel/UC1/}UseCase1Service', flowOperationName = '{http://petals.com/bpel/UC1/}process', filePath = '/home/user/filetransferDir/'test.txt'
06
... traceCode = 'consumeFlowStepEnd', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = '1aakflk333-sdflkj-5854'
07
... traceCode = 'consumeFlowStepBegin', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = '1aakflk333-sdflkj-5854', flowInterfaceName = '{http://petals.com/bpel/UC1/}UseCase1', flowServiceName = '{http://petals.com/bpel/UC1/}UseCase1Service', flowOperationName = '{http://petals.com/bpel/UC1/}process', eventTime = 'timestamp'
08
... traceCode = 'consumeFlowStepEnd', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = '1aakflk333-sdflkj-5854'
09
... traceCode = 'provideFlowStepBegin', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'aa5lk333-sdflkj-5854', flowStepInterfaceName ='{http://petals.com/bpel/UC1/}UseCase1', flowStepServiceName = '{http://petals.com/bpel/UC1/}UseCase1Service', flowStepOperationName = '{http://petals.com/bpel/UC1/}process', flowStepEndpointName = 'UseCase1Endpoint', flowPreviewStepId = '1aakflk333-sdflkj-5854'
10
... traceCode = 'provideFlowStepEnd', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'aa5lk333-sdflkj-5854'
11
... traceCode = 'provideFlowStepBegin', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'bb5lk333-sdflkj-5854', flowStepInterfaceName ='{http://petals.com/bpel/UC1/}UC1SubFlow1', flowStepServiceName = '{http://petals.com/bpel/UC1/}UC1SubFlow1Service', flowStepOperationName = '{http://petals.com/bpel/UC1/}process', flowStepEndpointName = 'UC1SubFlow1Endpoint', flowPreviewStepId = 'aa5lk333-sdflkj-5854'
12
... traceCode = 'provideFlowStepEnd', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'bb5lk333-sdflkj-5854'
13
... traceCode = 'provideFlowStepBegin', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'cc42lk333-sdflkj-5854', flowStepInterfaceName ='{http://petals.com/}Validation', flowStepServiceName = '{http://petals.com/}ValidationService', flowStepOperationName = '{http://petals.com/}ValidationString', flowStepEndpointName = 'validation', flowPreviewStepId = 'bb5lk333-sdflkj-5854', operation = 'validate', schema = 'schema.xsd'
14
... traceCode = 'provideFlowStepEnd', flowInstanceId =  'f586fc9b0-b374-00216a65569e', flowStepId = 'cc42lk333-sdflkj-5854'
15
... traceCode = 'provideFlowStepBegin', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'dqflk333-sdflkj-5854', flowStepInterfaceName ='{http://act.org/}Echo', flowStepServiceName = '{http://act.org/}EchoService', flowStepOperationName = '{http://act.org/}echoString', flowStepEndpointName = 'echo', flowPreviewStepId = 'cc42lk333-sdflkj-5854'
16
... traceCode = 'provideFlowStepEnd', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'dqflk333-sdflkj-5854'
17
... traceCode = 'provideExtFlowStepBegin', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'dqflk333-sdflkj-5854', requestedURL = 'http://192.168.1.140:8080/petals/services/EchoSOAPBinding/'
18
... traceCode = 'provideExtFlowStepEnd', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'dqflk333-sdflkj-5854'
19
... traceCode = 'provideFlowStepBegin', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'eelflk333-sdflkj-5854', flowStepInterfaceName ='{http://petals.com/}SendMail', flowStepServiceName = '{http://petals.com/}SendMailService', flowStepOperationName = '{http://petals.com/}send', flowStepEndpointName = 'send', flowPreviewStepId = 'dqflk333-sdflkj-5854'
20
... traceCode = 'provideFlowStepEnd', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'eelflk333-sdflkj-5854'
21
... traceCode = 'provideExtFlowStepBegin', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'eelflk333-sdflkj-5854', emailAddress = 'test@petalslink.com', smptUrl = 'smpt.petalslink.com'
22
... traceCode = 'provideFlowStepBegin', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'ffyflk333-sdflkj-5854', flowStepInterfaceName ='{http://petals.com/}Transformation', flowStepServiceName = '{http://petals.com/}TransformationService', flowStepOperationName = '{http://petals.com/}transformationString', flowStepEndpointName = 'transformation', flowPreviewStepId = 'eelflk333-sdflkj-5854', operation = 'transform', stylesheet = 'transformation.xsl', listParameters = 'nom1:value1,nom2:value2'
23
... traceCode = 'provideFlowStepEnd', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'ffyflk333-sdflkj-5854'
24
... traceCode = 'provideFlowStepBegin', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'gg2aflk333-sdflkj-5854', flowStepInterfaceName ='{http://petals.com/}DirOpSftp', flowStepServiceName = '{http://petals.com/}DirOpSftpService', flowStepOperationName = '{http://petals.com/}dirOp', flowStepEndpointName = 'dirOp', flowPreviewStepId = 'ffyflk333-sdflkj-5854'
25
... traceCode = 'provideFlowStepEnd', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'gg2aflk333-sdflkj-5854'
26
... traceCode = 'provideExtFlowStepBegin', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'gg2aflk333-sdflkj-5854', operation ='dirOperation', fileName = 'test.txt', destDirName = '/home/user/test', user = 'userTest', sftpURL = 'sftp://localhost:port/test'
27
... traceCode = 'provideExtFlowStepEnd', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'gg2aflk333-sdflkj-5854'
28
... traceCode = 'provideFlowStepBegin', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'hhz2aflk333-sdflkj-5854', flowStepInterfaceName ='{http://petals.com/}PutFtp', flowStepServiceName = '{http://petals.com/}PutFtpService', flowStepOperationName = '{http://petals.com/}putOperation', flowStepEndpointName = 'putOp', flowPreviewStepId = 'gg2aflk333-sdflkj-5854'
29
... traceCode = 'provideFlowStepEnd', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'hhz2aflk333-sdflkj-5854'
30
... traceCode = 'provideExtFlowStepBegin', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'hhz2aflk333-sdflkj-5854', operation = 'put', fileName = 'test.txt', destDirName ='/home/user/test', user = 'userTest', ftpURL = 'ftp://localhost:port/test'
31
... traceCode = 'provideFlowStepBegin', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'iit5lk333-sdflkj-5854', flowStepInterfaceName ='{http://petals.com/eip/UC1/}UC1SubFlow2', flowStepServiceName = '{http://petals.com/eip/UC1/}UC1SubFlow2Service', flowStepOperationName = '{http://petals.com/eip/UC1/}split', flowStepEndpointName = 'UC1SubFlow2Endpoint', flowPreviewStepId = 'hhz2aflk333-sdflkj-5854'
32
... traceCode = 'provideFlowStepEnd', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'iit5lk333-sdflkj-5854'
33
... traceCode = 'provideFlowStepBegin', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'jjrbflk333-sdflkj-5854', flowStepInterfaceName ='{http://petals.com/}SelectSql', flowStepServiceName = '{http://petals.com/}SelectSqlService', flowStepOperationName = '{http://petals.com/}select', flowStepEndpointName = 'select', flowPreviewStepId = 'iit5lk333-sdflkj-5854'
34
... traceCode = 'provideFlowStepEnd', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'jjrbflk333-sdflkj-5854'
35
... traceCode = 'provideExtFlowStepBegin', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'jjrbflk333-sdflkj-5854', operationSQL = 'select name from USER;', user = 'userTest', jdbcURL = 'jdbc:h2:mem:testBDD'
36
... traceCode = 'provideExtFlowStepEnd', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'jjrbflk333-sdflkj-5854'
37
... traceCode = 'provideFlowStepBegin', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'kko95lk333-sdflkj-5854', flowStepInterfaceName ='{http://petals.com/bpel/UC1/}UC1SubFlow3', flowStepServiceName = '{http://petals.com/bpel/UC1/}UC1SubFlow3Service', flowStepOperationName = '{http://petals.com/bpel/UC1/}process', flowStepEndpointName = 'UC1SubFlow3Endpoint', flowPreviewStepId = 'aa5lk333-sdflkj-5854'
38
... traceCode = 'provideFlowStepEnd', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'kko95lk333-sdflkj-5854'
39
... traceCode = 'provideFlowStepBegin', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'llqhflk333-sdflkj-5854', FlowStepInterfaceName ='{http://petals.com/}GetFiletransfer', flowStepServiceName = '{http://petals.com/}GetFiletransferService', flowStepOperationName = '{http://petals.com/}getFile', flowStepEndpointName = 'getFile', flowPreviewStepId = 'kko95lk333-sdflkj-5854'
40
... traceCode = 'provideFlowStepEnd', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'llqhflk333-sdflkj-5854'
41
... traceCode = 'provideExtFlowStepBegin', flowInstanceId = 'f586fc9b0-b374-100216a65569e', flowStepId = 'llqhflk333-sdflkj-5854', operation = 'ge'', fileName = 'test.txt', destDirName = '/home/user/test'
42
... traceCode = 'provideExtFlowStepEnd', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'llqhflk333-sdflkj-5854'
43
... traceCode = 'provideFlowStepBegin', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'mmpqflk333-sdflkj-5854', FlowStepInterfaceName ='{http://petals.com/}JavaAppli', flowStepServiceName = '{http://petals.com/}JavaAppliService', flowStepOperationName = '{http://petals.com/}calcul', flowStepEndpointName = 'calculJava', flowPreviewStepId = 'aa5lk333-sdflkj-5854', class = 'com.ebmwebsourcing.petals.TestService'
44
... traceCode = 'provideFlowStepEnd', flowInstanceId = 'f586fc9b0-b374-00216a65569e', flowStepId = 'mmpqflk333-sdflkj-5854'

Logs content & formatting of MONIT level

The default directory for Petals ESB log files is $PETALS_HOME/logs (you can change logs directory and logs level by following the related configuration documentation). This directory is shared between:

  • the petals.log file which holds all informations about bus runtime (bus starting, installing or removing a component, etc);
  • a flowMonitoring directory.

The flowMonitoring directory itself will contain subfolders, each one being named after a flow's flowInstanceId. Each such subfolder will contain a file flow.log which will record all logs relating to this particular flow instance (from INFO to MONIT level, or even FINEST level when active).

Whatever their level and usage, logs names (traces in petals.log and flow.log) are always structured like this:
Petals-node-name Date LEVEL [loggerName] : Message
FIXME (Petals-node-name : représente le noeud sur lequel se fait les logs) :

On MONIT level, log messages packs two kind of informations:

  • standard parameters for this level (are included in every component)
  • specific parameters for some logging component.

Standard parameters

Parameters included in every trace of MONITORING level
traceCode: (represents) the position of the trace in the flow (confer last paragraph).

flowInstanceId: (represents) the id of a flow instance.

flowStepId: the unique id of a flow step.

dumpPath: path for the directory where the IN or OUT message is saved.

Parameters included only in starting step's traces (MONIT level)

For a Consume Service

flowStepInterfaceName: interface name of the first provide invoked (consume service only).

flowStepServiceName: service name of the first provide service invoked (consume service only).

flowStepOperationName: operation name of the first provide service invoked (consume service only).

For a Provide Service

traceCode: (represents) the position of the trace in the flow (confer last paragraph).

flowStepInterfaceName: interface name of invoked provide service.

flowStepServiceName: service name of invoked provide service.

flowStepOperationName: operation name of invoked provide service.

flowStepEndpointName: endpoint name of invoked provide service.

flowPreviousStepId: flowStepId of service which initiated the call (provide service only). |

Parameters recorded in MONIT level when a step fails (ERROR or FAULT state):

failureMessage: content of a fault message or an error message .

Specific parameters

These are all parameters which are recorded when a step is starting. It is varying depending on the component.
The table here under presents these traces, varying on component itself and its configuration (consume or provide).

Component Consume Provide
bc-soap requestedURL: The URL used by the webservice client to invoke the service requestedURL: The URL of the external webservice invoked
bc-mail scheme, host, port, user, folder emailAddress
bc-sftp N/A patterns, folder
bc-ftp N/A patterns, folder
bc-filetransfer filePath fileName, destDirName
bc-sql N/A operationSQL
se-bpel No specific information No specific information
se-eip No specific information No specific information
se-validation N/A No specific information
se-xslt N/A No specific information
se-quartz eventTime N/A
se-jsr-181 N/A No specific information


Definitions of traceCode:

  • consumeFlowStepBegin: record the fact that an external event is received by a consumer. Such a record can only occur on the consume side of binding-components,
  • consumeFlowStepEnd: record the succeeded end of the external event processing,
  • consumeFlowStepFailure: record the failure of the external event processing,
  • provideFlowStepBegin: record of the fact that a provide service receives a call/request from a service consumer. Such a record occurs on service-engine or on the provider side of binding-components,
  • provideFlowStepEnd: record of the fact that a service provider sends its answer or acknowledgment,
  • provideFlowStepFailure: record the failure of the service provider processing.
  • provideExtFlowStepBegin: record of the fact that a service provider calls another service (external call). Such a record can only occur on the provider side of binding-components,
  • provideExtFlowStepEnd: record of the fact that a service provider receives the answer or acknowledgement to its external call,
  • provideExtFlowStepFailure: record that a service provider receives an error from its external call,

Dumping content of message payload

When you activate the log handler PetalsPayloadDumperFileHandler, any log message is saved as following:

  • the log trace is logged in the log file identified by the following pattern: $PETALS_HOME/logs/flow-monitoring/<flow instance id>/petals.log. The log file can be overridden by configuration of the log handler.
  • for log trace with level MONIT:
    • the content of service request and reply is dumped in a file identified as following: $PETALS_HOME/logs/flow-monitoring/<flow instance id>/<flow step id>_<trace code>.xml
    • the file name of the dumped message is added as a new attribute payloadContentDumpFile of the MONIT log trace.

Dumping exchange content

When you activate the log handler PetalsExchangeDumperFileHandler, any log message is saved as following:

  • the log trace is logged in the log file identified by the following pattern: $PETALS_HOME/logs/flow-monitoring/<flow instance id>/petals.log. The log file can be overridden by configuration of the log handler.
  • for log trace with level MONIT, the content of the message exchange is dumped in a file identified as following: $PETALS_HOME/logs/flow-monitoring/<flow instance id>/<flow step id>_<trace code>.log
    • the exchange content logged is composed of:
      • message exchange identifier,
      • message exchange pattern,
      • message exchange status,
      • interface name of the service provider invoked,
      • service name of the service provider invoked,
      • endpoint,
      • name of operation invoked,
      • message exchange properties,
      • normalized messages of the message exchange, with for each normalized message:
        • normalized message properties,
        • normalized message content, the XML payload,
        • attachments, with for each attachment:
          • attachment name,
          • attachment size if available,
          • attachment content, that will be available in a next version,
      • fault of the message exchange if exist. Dumped as a normalized message,
      • error if exists. Dumped as an error stack trace.
Enter labels to add to this page:
Please wait 
Looking for a label? Just start typing.