Reading and Tracking Requests in Retail Pro Prism Log Files

To track requests in Retail Pro Prism log files, especially on log level 3 with overlapping requests, there are TWO things you need to track:

1. Requests related to the same security session
2. Log lines for one particular request from beginning to end
    

1. Requests related to the same security session
I.e. Requests from the same workstation and the same logged-in user

To follow the stream of requests for the same session, search for the session token. It is logged as a long string of characters and digits in the Auth-Session line.

Example

POSV1:
2019.11.13.01.00.44.339 [3728] Information ------
Auth-Session: 204AC3855B7D498FB7933187BCA992C1

BackOffice:
2019.11.13.04.00.55.249 [5412] Information ------
Auth-Session: 204AC3855B7D498FB7933187BCA992C1

Common:
2019.11.13.01.00.44.323 [1196] Information ------
Auth-Session: 204AC3855B7D498FB7933187BCA992C1


Below is an example of the full section of the log. We are looking to identify the Namespace, URL, Method and the Auth-Session token.

To find out what requests were sent prior to or after the one you are currently examining, search for the session token backward or forward in the log file. You should be able to see those log lines on log levels 2 and 3.

If requests from the SAME session are made to different modules (POSV1, BackOffice, Common) they will show the same Auth-Session value, so you can track whether or not that session was talking to multiple services.

Note: Do not pay attention to the CorrelationID. CorrelationID is used for tracking interactions between Apache and our services, and is useful only for developers and only in very special circumstances.

 

2. Log lines processing one particular request from beginning to end
Very important for multiple requests logging in parallel


Track log lines

In this case you need to find the beginning of the request and use the thread ID to track the log lines generated by that specific consumer while it was processing that specific request.

The Thread ID is the number denoted inside square brackets. In this example, the thread ID is 6004.

Locate Request Entry and Exit

The next step is to find where that requests starts and ends. Look for the very first ">> Entry >>" line where it says xxxxxxMessageConsumer.ProcessMessage.

There will be a single blank space on each side of the "Entry" keyword. That is the beginning of the message handler.

Replace ">> Entry >>" with "<< Exit  <<"

There will be a single blank space to the left and TWO blank spaces to the right of the "Exit" keyword.

Keep the rest of the line as is, with FOUR blank spaces after the thread ID, like this:

Keep the very same thread ID. If you search FORWARD for that line, it will be the VERY LAST log line for that specific message.

Note: It might end up being in the next log file, so if you did not find it, search in the next file. Or, if you are looking at the last request in the log file it might still be buffered in memory. Wait until the buffer is saved.


Since consumer threads do not change the thread ID while processing requests, each and every line between the Entry and Exit lines that have the same thread ID belong to the same consumer thread working on the same request.

If you see another line in between with a DIFFERENT thread ID, ignore it. It is coming from a different request.

Note: Each consumer has its own thread ID but there is no correlation between the SESSION and THREAD ID. Any consumer can process any request as long as it is available.

There is no rule stating that if you process a GET request for a document in thread XYZ, the same thread will process the next request for the same session. THREAD IDs are only important WITHIN the same request.

For tracking multiple requests use Auth-Session instead.