Distributed Server Option logging
logs track the steps and events of distributed operations handled by the server. You can activate logging only on that have a license for . The following table lists the log files for Java.
log files
By default, the log files are stored in these directories:
- (UNIX) ARSystemServerInstallDir/db/
- (Windows) ARSystemServerInstallDir\Arserver\Db
You can change the path or file names of the log files in the AR System Administration: Server Information form. (See Configuring-Distributed-Server-Option-logging.)
When you activate logging, it starts immediately. If you restart the or reactivate logging after deactivating it, each 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 to append the new log to the existing log (see Setting-log-files-options).
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 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
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
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
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*