log_api

It is possible to log many aspects of the system.

In table dbo.log_api, in standard AGR, we should be able to find nearly all user changes to the system. This can be necessary for reasons such as system optimizations, GDPR complianace or simply user-training.

Some examples of what might be necessary to track via table dbo.log_api:

  • Changes to order line data (for different use than Usage statistics module)
  • Changes to data series (Planner)
  • Changes to editable elements (like Adjusted sales)

Usage statistics

This add-on module logs user changes to order proposals.


log_api

Many AGR setups use table prod.log_api to monitor user actions, and other system activities. Other setups also use this to measure order accuracy (changed lines) or performance in the order view (time to update order line Qty for example). Some customers insists on this for GDPR compliance.

We need to consider a few things when trying to log into dbo.log_api on the prod database.

Setup

Logging is enabled in AGR by making sure the following is in the web/web.config on the web site. This should already be in place but necessary to make sure all is correctly set.

<appSettings>
<add key="logWebApiRequests" value="true"/>
</appSettings>

In file web/log4net.config on the web site make sure there is a parameter block like seen below. This block is missing in 5.3.2 install/upgrade is causes logging to fail silently.

<parameter>
  <parameterName value="@elapsed_time_ms" />
  <dbType value="Int32" />
  <layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%property{ElapsedTimeMs}" />
 </layout>
</parameter>

Logging is done via buffer in web/log4net.config that writes down to SQL either instantly (1) or by some other number like 100. 1 should only be used for initial testing and then raised. Note: If the application pool is refreshed while actions are in the buffer they will be lost. Thus it is best to try to keep the buffer number not too high.


<bufferSize value="1"/>

Restart the website just in case and then you should have logging.

Use of log_api data

There are many ways to work with log_api data. Two of the most common ones are monitoring of order line changes or updates to planner data series.

Examples of data:
In the example below user 33 changed order line id 25236286 to qty of 0.

user_id request_uri request_body
33 http://10.11.8.204/api/orders/25236286/update_order_line?showBusy=false {“name”:“unit_qty_chg”,“value”:0}

1. Orders. Changes to order lines by users

Some specific setups need to monitor user changes in different ways than standard AGR offers. Then we can adjust our setups by using log_api directly in various ways.

In the example below we have been custom logging user changes to procedure dbo.orders_update_values to newe loggig table to track actual user changes. We then need to find the user reponsible for this change (user_id was not available in that procedure until AGR 6.1). In this case we try to find matching line in dbo.log_api to the log date we already have. To reduce changes of false positives we bracked the timestamp as narrow as possible (1000ms before log date and 500ms after it), this needs fine tuning on each setup but this can be nearly 100% accurate.


--  Update order_line logging table, -1200ms +300ms against log_api
   UPDATE o
        SET o.user_id = l.user_id
        FROM cus.bi_log_order_line_changes o INNER JOIN
        (
           --Test for x-number of milliseconds to have simpler query
          SELECT 
              olc.id AS line_id, olc.log_date, olc.order_line_id, olc.qty, api.user_id, api.request_body
              , api.timestamp AS api_timestamp, api.elapsed_time_ms, api.cus_order_line_id
              , DATEADD(ms, -1000, api.timestamp) AS from_date
              , DATEADD(ms, 500, api.timestamp) AS to_date
              , DATEDIFF(ms, olc.log_date, api.timestamp) AS difference_ms
          FROM cus.bi_log_order_line_changes olc
        INNER JOIN dbo.order_lines ol ON ol.id = olc.order_line_id
        INNER JOIN dbo.items i ON i.id = ol.item_id
        INNER JOIN dbo.item_order_routes ior ON ior.item_id = ol.item_id
              INNER JOIN dbo.log_api api ON api.cus_order_line_id = olc.order_line_id 
              AND olc.log_date BETWEEN DATEADD(ms, -1000, api.timestamp) AND DATEADD(ms, 500, api.timestamp)
      WHERE 
          olc.event_type_id = 100 AND olc.user_id IS NULL
          AND CHARINDEX(CAST(CASE
                    WHEN olc.qty % ior.order_multiple > 1 THEN olc.qty % ior.order_multiple -- Was this a purchase unit?
                    ELSE olc.qty END 
                  AS VARCHAR(30)),api.request_body) > 0  
        ) l
        on o.[order_line_id] = l.[order_line_id] 
      AND o.id = l.line_id

In the example above we rely on new column cus_order_line_id in the dbo.log_api to mark entries that are changes to order lines. We populate that column as follows:


ALTER TABLE log_Api ADD cus_order_line_id AS
       CASE WHEN CHARINDEX('/update_order_line', request_uri) > 0 
                     THEN SUBSTRING(request_uri,CHARINDEX('/api/orders/', request_uri) + 12, CHARINDEX('/update_order_line', request_uri) - CHARINDEX('/api/orders/', request_uri) - 12)
                     ELSE NULL
                     END PERSISTED

2. Planner. User changes to data series

We can use table dbo.log_api to find user changes to planner baseline or other data series. See more in User statistics add on page.

It is also possible to log directly from procedure dbo.de_execute_action into custom logging table and bypass dbo.log_api altogether (this is actually safer in case we loose the buffer as mentioned above). If this route is taken please consider updates to AGR so that this change is not overwrittten by next update.