Investigate Behavior of AIMMS PRO Job

An AIMMS PRO job may spend more time than the corresponding procedure on the client side. In this article we set out to answer the following questions:

  1. How to reduce the execution time of an AIMMS PRO job?

  2. How to find out what went wrong with an AIMMS PRO job?

Tip

A first check is to search for : duration and for transmitted in the session log files; this may provide a clue quickly of where a bottleneck might be.

To provide a structural answer for your application, we need to dive into the workings of the procedure PRO::DelegateToServer.

As the AIMMS PRO job realizing the delegated procedure runs in a different process, potentially on a different host, the necessary actions taken by PRO::DelegateToServer are illustrated in the picture below:

../../_images/actions-delegate.png

Actions taken by PRO::DelegateToServer:

  1. Client side: Create a case file to be used as input

  2. Copy the case file to the AIMMS PRO server

  3. On the AIMMS PRO server, wait for a server license

  4. On the AIMMS PRO server, compile and initialize the AIMMS Project

  5. On the AIMMS PRO server, read the input case file

  6. On the AIMMS PRO server, execute the procedure that is invoked by pro::DelegateToServer

  7. On the AIMMS PRO server, create a case file with the results

  8. Client side: read the case file with results

In this article, we will detail for each of the above actions, how to investigate behavior.

Client side: Create a case file to be used as input

The more information that is shared between the client session and the solver session, the longer it takes (creating, transmitting, reading). The information is shared in the form of a case file. The amount of information in this case file is determined by the set of identifiers and their cardinalities.

The identifiers of the input case created by pro::DelegateToServer is defined by pro::ManagedSessionInputCaseIdentifierSet, minus the identifiers in pro::ManagedSessionRemoveFromCaseIdentifierSet. However, the delegated job may only require the data of a subset of the identifiers in pro::ManagedSessionInputCaseIdentifierSet. To measure how long it takes to create an input case, please execute the procedure SaveInputCase, coded below, with the AIMMS profiler on:

 1Procedure SaveInputCase {
 2    Body: {
 3        s_InputCaseIdentifierSet :=
 4            pro::ManagedSessionInputCaseIdentifierSet -
 5            pro::ManagedSessionRemoveFromCaseIdentifierSet ;
 6        CaseFileSave(
 7            url      :  "testcase.data",
 8            contents :  s_InputCaseIdentifierSet);
 9    }
10    Set s_InputCaseIdentifierSet {
11        SubsetOf: AllIdentifiers;
12    }
13}

Remarks about the above code:

  1. pro::ManagedSessionInputCaseIdentifierSet is initialized to AllIdentifiers

  2. pro::ManagedSessionRemoveFromCaseIdentifierSet is initialized to AllDefinedParameters

  3. Thus, by default defined parameters are not transferred, but defined sets are. Evaluating the definitions of these sets may still take significant time. If so, the AIMMS profiler will identify the sets that take significant time. Some of these sets can be safely added to pro::ManagedSessionRemoveFromCaseIdentifierSet. For instance, those with dimension 2 or higher, as illustrated by adding the following assignment to PostMainInitialization:

    1pro::ManagedSessionRemoveFromCaseIdentifierSet := AllDefinedParameters +
2            { indexIdentifiers | indexIdentifiers in AllDefinedSets and
3                IdentifierDimension(indexIdentifiers) >= 2 };

  4. Please see reduce client server exchange on tips for assigning pro::ManagedSessionInputCaseIdentifierSet to just those that are relevant for the job at hand.

Note

Software evolution: pro::ManagedSessionRemoveFromCaseIdentifierSet is applied to reduce the set of identifiers transferred since AIMMS 4.59.2.

Copy the case file to the AIMMS PRO server

To transfer items, transfer speed and item size do matter. To reduce the item size is discussed in the previous section. The transfer speed depends on the connection and distance. Obviously, when the client and server sessions are executed on the same host or the hosts are in the same domain, the transfer speed is high. On the other hand, when these hosts are in different continents, then the transfer speed may very well be low.

To investigate how much time is spent for the case transfer, we have to look in the session log file of the solver session. This file can be found in the AIMMS PRO data folder, by default C:\ProgramData\AimmsPRO, subfolder Log\Sessions. The name of this log file is a GUID with extension .log. On a test server, the file was named D:\ProgramData\AimmsPRO\Log\Sessions\f9706ac8-841f-4b35-bc74-57863e82e630-1.log

To determine the time, obtain the session log file for the solver session and search for “CaseLoad : duration”:

2019-09-25 09:39:57,835 0x0000c2d0 [INFO] {AIMMS.DataManagement.DataManager} CaseLoad : duration 38093 ms

and a few lines above that:

2019-09-25 09:39:19,744 0x0000c2d0 [INFO] {PRO.Common.GenericFileRetriever} GenericReceiveFile( ..., fullPath = 'D:/ProgramData/AimmsPRO/Data/Publishing/MODELS/6cfce02e-9d7a-439f-b1ce-19f936247e77/PROTemp-058DBE41/cases.data', ... ) Transmitted 889248 KB in 1.93 seconds ( 460750 KB/s)

Because of the superfluous identifier, we’re transmitting a case of 800+ Mb which takes 38 seconds here.

Anyway, now that we have this log file open, we may want to search for other occurrences of the word “duration”, to see if anything interesting pops up.

On the AIMMS PRO server, wait for a server license

This is also known as wait time or queueing time. This can be obtained from the Jobs tab in the AIMMS PRO Portal as illustrated in the image below:

../../_images/JobsTabForQueueing.png

In the example above, the job didn’t have to wait for other jobs. Clearly, the queueing time depends on the load of the AIMMS PRO server, but that falls outside the scope of this article.

On the AIMMS PRO server, compile and initialize the AIMMS Project

A solver session starts with opening the project, including running initialization procedures of the Main model and running the initialization procedures of each of its libraries.

By adding the code ProfilerStart() at the top of your MainInitialization procedure, you can measure how long do these initialization procedures take for your project. After adding this line, close and reopen your AIMMS project. Profiler -> Results Overview will give you the numbers on client side.

../../_images/ProfiledClientSideInitialization.png

Once you are satisfied with the initialization times of your project on client side, you might want to check this on the server side as well. How to check the timings server side is discussed below: see On the AIMMS PRO server, execute the delegated procedure.

On the AIMMS PRO server, read the input case file

This action, and subsequently the time it takes, is closely linked to the size of the case file as discussed above.

On the AIMMS PRO server, execute the delegated procedure

On the AIMMS PRO server, create a case file with the results

This is the same as section Client side: Create a case file to be used as input, except the other way around and the identifier pro::ManagedSessionOutputCaseIdentifierSet

Client side: read the case file with results

This is the same as section On the AIMMS PRO server, read the input case file.