This documentation supports the 20.02 version of Remedy Action Request (AR) System.

To view an earlier version, select the version from the Product version menu.


Filter log

The filter log file shows all of the filters that were checked during an operation. If a filter was executed, the log also provides a list of the operations performed. By default, the log file is named arfilter.log.

This log is especially useful for checking the interaction of your filters and for verifying whether a filter is performing correctly.

The filter log format is similar to the SQL log format, but the information in the filter log is displayed over multiple lines. The log has the following characteristics:

  • Each line starts with a tag that identifies it as being a filter logging line (<FLTR> ).
  • A time stamp line is written for every operation that can trigger filters.
  • A line indicates that processing has started and the operation is being performed. This line now includes the filter stack level and filter number within the stack.
  • As each filter is checked, a message is written that includes the name of the filter, its escalation order, an indication of whether the filter passed the qualification, and any actions taken with the results of those actions.
  • The last line contains a closing time stamp.

Phases 1, 2 and 3 of filter processing appear in the filter log. As BMC Remedy AR System checks filters, all notify and run process actions are deferred to phase 3. When phases 1 and 2 are completed, and the database has been updated, phase 3 begins. In phase 3, all deferred filter actions are run. This information enables you to track which filters are being checked, which filters are running, and the actions that are being performed. For more information about filter processing, see Filter processing in BMC Remedy AR System server.

Following is a sample filter log file:

<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000088685> <Queue: Fast      > <Client-RPC: 390620   > <USER: Remedy Application Service                   > <Overlay-Group: 1         > /* Mon Mar 30 2015 00:23:48.8020 */    Start filter processing (phase 1) -- Operation - GET on Configuration ARDBC - 000000000000037
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000088685> <Queue: Fast      > <Client-RPC: 390620   > <USER: Remedy Application Service                   > <Overlay-Group: 1         > /* Mon Mar 30 2015 00:23:48.8020 */    End of filter processing (phase 1) -- Operation - GET on Configuration ARDBC - 000000000000037
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         > /* Mon Mar 30 2015 00:26:45.0960 */    Start filter processing (phase 1) -- Operation - SERVICE on NGC:Calendar - <NULL>
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         > /* Mon Mar 30 2015 00:26:45.1110 */ <Filter Level:0 Number Of Filters:0> Checking "NGC:CAL:GetBroadcastCount" (10)
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         >    --> Passed -- perform actions
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         >         0 : Call Guide "NGC:CAL:GetBroadcastCount_G"
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         > /* Mon Mar 30 2015 00:26:45.1420 */ <Filter Level:0 Number Of Filters:1> Checking "NGC:CAL:GetBroadcastLastViewDateTime" (0)
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         >    --> Passed -- perform actions
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         >         0 : Set Fields
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         >               z1D_BroadcastLastViewDateTime (302796500) = 
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         > /* Mon Mar 30 2015 00:26:45.1420 */ <Filter Level:0 Number Of Filters:2> Checking "NGC:CAL:Broadcast Last Viewed Date Default" (0)
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         >    --> Passed -- perform actions
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         >         0 : Set Fields
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         >               z1D_BroadcastLastViewDateTime (302796500) = 12/6/1973 12:00:00 PM
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         > /* Mon Mar 30 2015 00:26:45.1580 */ <Filter Level:0 Number Of Filters:3> Checking "NGC:CAL:Broadcast_Get_Counts_Set112" (200)
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         >    --> Failed qualification -- perform else actions
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         > /* Mon Mar 30 2015 00:26:45.1580 */ <Filter Level:0 Number Of Filters:4> Checking "NGC:CAL:Broadcast Query For Count_Int" (800)
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         >    --> Passed -- perform actions
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         >         0 : Set Fields
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         >               z1D_BroadcastQual (301497300) = ('Broadcast Start Date' < "3/30/2015 12:26:45 AM") AND (('Broadcast Start Date' > "6/12/1973 12:00:00 PM") OR ('Last Modified Date' > "6/12/1973 12:00:00 PM")) AND (('Broadcast End Date' >= "3/30/2015 12:26:45 AM") OR ('Broadcast End Date' = $\NULL$))
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         >         1 : Set Fields
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         >               z1d_TempBrdMsg (302888800) = 
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         >         2 : Set Fields
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         >               z1D_NewBroadcastCount (302889100) = 0
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         > /* Mon Mar 30 2015 00:26:45.1740 */ Call Guide "NGC:CAL:GetBroadcastCount_G" (return).
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000000017> <Queue: Fast      > <Client-RPC: 390620   > <USER: Demo                                         > <Overlay-Group: 1         > /* Mon Mar 30 2015 00:26:45.1740 */    End of filter processing (phase 1) -- Operation - SERVICE on NGC:Calendar - <NULL>
<FLTR> <TrID: Ycc4EXa4Q_2u8fKTGcAcOg:0000064> <TID: 0000000359> <RPC ID: 0000088737> <Queue: Fast      > <Client-RPC: 390620   > <USER: Remedy Application Service                   > <Overlay-Group: 1         > /* Mon Mar 30 2015 00:31:50.2350 */    Start filter processing (phase 1) -- Operation - GET on Configuration ARDBC - 000000000000037



The filter in the example log performed two actions, a message and an alert. The alert was deferred to phase 3 filter actions. The log also shows the execution of another filter, Alert Events, which created the alert performed by the original filter. The execution of another filter will also occur on a Push Fields action. When the log indicates a failed qualification, this does not mean that the filter malfunctioned. This means that the qualification was not met for this operation, so the else action runs if present.

Tracking filter overlays

When the server executes a filter overlay, the filter log uses the real name of the overlay (<filterObjectName__o>). It also records this message:

skipping overlaid object <filterObjectName>

When overlays are disabled on the server and the server executes an overlaid filter object, it records this message:

skipping overlay object <filterObjectName__o>

For information about overlay objects, see Customizing applications using overlays and custom objects.

Was this page helpful? Yes No Submitting... Thank you

Comments