Distributed Server Option logging

Distributed Server Option(DSO) logs track the steps and events of distributed operations handled by the DSO server. You can activate DSO logging only on AR System server that have a license for DSO.

Related topics

Enabling-and-analyzing-logs

Analyzing-logs

The following table lists the DSO log files for Java.

DSO log files


By default, the DSO log files are stored in the following directories:

  • (UNIX) ARSystemServerInstallDir/db/
  • (Windows) ARSystemServerInstallDir\Arserver\Db

You can change the path or file names of the DSO log files in the AR System Administration: Server Information form. (See Configuring-Distributed-Server-Option-logging.)

When you activate DSO logging, it starts immediately. If you restart the AR System server or reactivate DSO logging after deactivating it, each DSO log file is emptied and restarted. By default, a .bak extension is added to the previous log file's name to create a backup log file. Alternatively, you can configure the AR System server to append the new log to the existing log (see Setting-log-files-options).

DSO Java log entries have the following syntax:

<timeStamp> <threadName> <logLevel> <loggerName> - <messageID> <message>
  • <timeStamp> specifies the time that the entry was written to the log.
  • <threadName> specifies the distributed pool that executed the distributed operation.
  • <logLevel> specifies the log level of the entry (INFO, WARN, ERROR).
  • <loggerName> specifies the Apache log4j logger object that wrote the entry.
  • <messageID> is the unique identifier of a message. The message ID is used to retrieve the appropriate localized message from the message catalog.
  • <message> is a localized message from the message catalog.

Example: The DSO server log file, Info log level

2011-05-19 23:18:08,046 [main] ALWAYS DSOServer  - 3244 Distributed Server Trace Log -- ON (AR Distributed Server 9.1 Build 001 201105182100)
2011-05-19 23:18:08,046 [main] INFO  DSOServer  - 1950 Initializing access to the AR System server
2011-05-19 23:18:09,625 [main] INFO  DSOServer  - 3234 JNI signal initialization done successfully
2011-05-19 23:18:09,640 [main] INFO  DSOServer  - 1951 Locating mapping and pending forms
2011-05-19 23:18:09,671 [main] INFO  DSOServer  - 1952 Mapping form -- Distributed Mapping
2011-05-19 23:18:09,671 [main] INFO  DSOServer  - 1953 Pending form -- Distributed Pending
2011-05-19 23:18:09,671 [main] INFO  DSOServer  - 1998 Distributed Pool form -- Distributed Pool
2011-05-19 23:18:09,671 [main] INFO  DSOServer  - 1845 Pending Errors form -- Distributed Pending Errors
2011-05-19 23:18:09,671 [main] INFO  DSOServer  - 1860 Distributed Server Logical Mapping Form -- Distributed Logical Mapping
2011-05-19 23:18:09,687 [main] INFO  DSOServer  - 5001 Pool default is marked as default

Example: pool1 log file, Info log level (a transfer with no problems)

2011-05-19 23:22:10,875 [Pool1] ALWAYS Pool1  - 1910 Distributed Server Trace Log -- ON
2011-05-19 23:22:10,890 [Pool1] INFO  Pool1  - 1950 Initializing access to the AR System server
2011-05-19 23:22:10,890 [Pool1] INFO  Pool1  - 1954 Get a list of items to process (stage 0)
2011-05-19 23:22:10,890 [Pool1] INFO  Pool1  - 3232 processPendingWork: lastEntryId = null
2011-05-19 23:22:10,906 [Pool1] INFO  Pool1  - 1989 Sleeping for 39:50 minutes
2011-05-19 23:22:35,796 [Pool1] INFO  Pool1  - 1954 Get a list of items to process (stage 0)
2011-05-19 23:22:35,796 [Pool1] INFO  Pool1  - 3232 processPendingWork: lastEntryId = null
2011-05-19 23:22:35,828 [Pool1] INFO  Pool1  - 1955 1 new item(s) found
2011-05-19 23:22:35,828 [Pool1] INFO  Pool1  - 1956 Processing item number 0
2011-05-19 23:22:35,828 [Pool1] INFO  Pool1  - 1957 Pending Type -- TRANSFER
2011-05-19 23:22:35,828 [Pool1] INFO  Pool1  - 1958 Source Form -- sender_form
2011-05-19 23:22:35,828 [Pool1] INFO  Pool1  - 1959 Source ID -- 000000000000002
2011-05-19 23:22:35,828 [Pool1] INFO  Pool1  - 3233 Pending other -- -m "source2target" -p "Pool1"
2011-05-19 23:22:35,828 [Pool1] INFO  Pool1  - 1964 Get source schema definition (stage 2)
2011-05-19 23:22:35,859 [Pool1] INFO  Pool1  - 1921 Using NEW cache definition for sender_form (prem5311)
2011-05-19 23:22:35,859 [Pool1] INFO  Pool1  - 1965 Get entry details (stage 3)
2011-05-19 23:22:35,859 [Pool1] INFO  Pool1  - 1966 Get mapping details (stage 4)
2011-05-19 23:22:35,859 [Pool1] INFO  Pool1  - 1937 Filter-specified mapping -- source2target
2011-05-19 23:22:35,859 [Pool1] INFO  Pool1  - 1836 Mapping source2target not in the cache or expired
2011-05-19 23:22:35,875 [Pool1] INFO  Pool1  - 1967 Mapping name -- source2target
2011-05-19 23:22:35,875 [Pool1] INFO  Pool1  - 1968 Target form -- receiver_form
2011-05-19 23:22:35,875 [Pool1] INFO  Pool1  - 1969 Target server -- prem5311
2011-05-19 23:22:35,875 [Pool1] INFO  Pool1  - 1843 Perform final checks (stage 5)
2011-05-19 23:22:35,875 [Pool1] INFO  Pool1  - 1970 Get target schema definition (stage 6)
2011-05-19 23:22:35,875 [Pool1] INFO  Pool1  - 1921 Using NEW cache definition for receiver_form (prem5311)
2011-05-19 23:22:35,875 [Pool1] INFO  Pool1  - 1971 Perform mapping (stage 7)
2011-05-19 23:22:35,890 [Pool1] INFO  Pool1  - 3224 Transfer operation info : Transfer Mode -- OWNERSHIP, Source Entry Id -- 000000000000002, Source Schema -- sender_form, Source Server -- prem5311, Target Schema -- receiver_form, Target Server -- prem5311
2011-05-19 23:22:35,890 [Pool1] INFO  Pool1  - 1944 Transfer successfully completed.  New/overwritten entry 000000000000002
2011-05-19 23:22:35,890 [Pool1] INFO  Pool1  - 1972 Mapping completed (stage 8)
2011-05-19 23:22:35,890 [Pool1] INFO  Pool1  - 1913 Next stage: ALL_DONE (Mapping done, update source entry), Status: DONE
2011-05-19 23:22:35,890 [Pool1] INFO  Pool1  - 1947 Updating entry with ID 000000000000002
2011-05-19 23:22:35,890 [Pool1] INFO  Pool1  - 1949 Successful update of entry
2011-05-19 23:22:35,890 [Pool1] INFO  Pool1  - 1924 Delete pending item -- 000000000025007
2011-05-19 23:22:35,906 [Pool1] INFO  Pool1  - 1989 Sleeping for 39:25 minutes

Example: pool1 log file, Error log level (a transfer with missing mapping)

2011-05-19 23:23:48,890 [Pool1] ALWAYS Pool1  - 1910 Distributed Server Trace Log -- ON
2011-05-19 23:23:48,890 [Pool1] INFO  Pool1  - 1950 Initializing access to the AR System server
2011-05-19 23:23:48,906 [Pool1] INFO  Pool1  - 1954 Get a list of items to process (stage 0)
2011-05-19 23:23:48,906 [Pool1] INFO  Pool1  - 3232 processPendingWork: lastEntryId = null
2011-05-19 23:23:48,906 [Pool1] INFO  Pool1  - 1989 Sleeping for 38:12 minutes
2011-05-19 23:23:54,750 [Pool1] INFO  Pool1  - 1954 Get a list of items to process (stage 0)
2011-05-19 23:23:54,750 [Pool1] INFO  Pool1  - 3232 processPendingWork: lastEntryId = null
2011-05-19 23:23:54,765 [Pool1] INFO  Pool1  - 1955 1 new item(s) found
2011-05-19 23:23:54,765 [Pool1] INFO  Pool1  - 1956 Processing item number 0
2011-05-19 23:23:54,765 [Pool1] INFO  Pool1  - 1957 Pending Type -- TRANSFER
2011-05-19 23:23:54,765 [Pool1] INFO  Pool1  - 1958 Source Form -- sender_form
2011-05-19 23:23:54,765 [Pool1] INFO  Pool1  - 1959 Source ID -- 000000000000003
2011-05-19 23:23:54,765 [Pool1] INFO  Pool1  - 3233 Pending other -- -m "source2target" -p "Pool1"
2011-05-19 23:23:54,765 [Pool1] INFO  Pool1  - 1964 Get source schema definition (stage 2)
2011-05-19 23:23:54,781 [Pool1] INFO  Pool1  - 1921 Using NEW cache definition for sender_form (prem5311)
2011-05-19 23:23:54,781 [Pool1] INFO  Pool1  - 1965 Get entry details (stage 3)
2011-05-19 23:23:54,796 [Pool1] INFO  Pool1  - 1966 Get mapping details (stage 4)
2011-05-19 23:23:54,796 [Pool1] INFO  Pool1  - 1937 Filter-specified mapping -- source2target
2011-05-19 23:23:54,796 [Pool1] INFO  Pool1  - 1836 Mapping source2target not in the cache or expired
2011-05-19 23:23:54,812 [Pool1] ERROR Pool1  - Exception
com.bmc.arsys.common.AppException: (1919): Mapping source2target does not exist
at com.bmc.arsys.dsoj.a8.a(Unknown Source)
at com.bmc.arsys.dsoj.g.a(Unknown Source)
at com.bmc.arsys.dsoj.g.a(Unknown Source)
at com.bmc.arsys.dsoj.g.void(Unknown Source)
at com.bmc.arsys.dsoj.g.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
2011-05-19 23:23:54,812 [Pool1] ERROR Pool1  - 1913 Next stage: GET_MAPPING (Get mapping details), Status: CANCEL
2011-05-19 23:23:54,812 [Pool1] ALWAYS Pool1  - 1844 Pending info: Pending ID -- 000000000025008, Type -- TRANSFER, Schema -- sender_form, Entry ID -- 000000000000003, Other -- -m "source2target" -p "Pool1"
2011-05-19 23:23:54,812 [Pool1] INFO  Pool1  - 1947 Updating entry with ID 000000000000003
2011-05-19 23:23:54,812 [Pool1] INFO  Pool1  - 1949 Successful update of entry
2011-05-19 23:23:54,921 [Pool1] ERROR Pool1  - 3003 Pending distributed operation canceled due to error
2011-05-19 23:23:54,921 [Pool1] ERROR Pool1  - 1844 Pending info: Pending ID -- 000000000025008, Type -- TRANSFER, Schema -- sender_form, Entry ID -- 000000000000003, Other -- -m "source2target" -p "Pool1"
2011-05-19 23:23:54,921 [Pool1] INFO  Pool1  - 1924 Delete pending item -- 000000000025008
2011-05-19 23:23:54,921 [Pool1] INFO  Pool1  - 1989 Sleeping for 38:6 minutes

 

Tip: For faster searching, add an asterisk to the end of your partial query. Example: cert*