Load Balancing in Qlikview Server Service (QVS) Does Not Behave As Expected, So How is it Supposed to Work?

One may find that in setting load balancing on the Qlikview Server Service (QVS), unexpected behavior is observed. This article answers:

1. How exactly is load balancing supposed to work, and 
2. How can one investigate what is actually happening on the server?

For information on how to make document listing more resilient on a busy QlikView, please review QlikView - How to enable load balancing when opening the AccessPoint to load the list of document.

Environments:

• Qlikview Server, All Versions

Expected Behavior

1. Document is requested via QVWS.
   1. ​Get the list of QVS servers the document can be loaded on; does the document have Availability rules?
      1. ​Yes: Return QVS servers where Document Available = "Always"
      2. No: Return all QVS servers​​​
   2. What is the Load Balancing Rule for the QVWS?
      1. Picked based on the rules as described in Requirements for Clustered QlikView Deployment​ > QVS Load Balancing Options

What about "Preload"?
If a document has been set to "Preload" for a particular QVS in its Availability rules, this means that document is loaded into memory at all times (otherwise the document may be unloaded when user sessions expire, for example) as described in Performance > Document Control. Keep in mind that it is still possible for a document to be preloaded on a particular QVS and the QVWS Load Balancing rule be set but due to "Load Document", but due to CPU and RAM the document may still load on a different QVS.

Actual Behavior
Qlikview Web Server (QVWS) directs traffic based on the Load Balancing rules, document Availability rules for the particular document requested, and finally the RAM and CPU resources of the target QVS. Ultimately to determine why a document was routed the way it was, it is necessary to know the RAM and CPU at the time of the document request. The best way to get this information is to enable Utilization Logging (QMC > System > {Web Server} > General > Logging Level) and examine the QVWS logs.

This will generate a separate file "Utilization YYYYMMDD.txt" that shows the CPU and Ram at the time a document was requested, and this (combined with Webserver logs, plus Load Balancing and document Availability rules) can be used to understand why a document was routed in a particular manner. 

1. Find an example where a document is being load balanced (search for "LoadBalancing - doc: UserDocuments\SOMEFILE.qvw" in the Web Server logs)
2. Find the corresponding entry in the Utilization logs (search for SOMEFILE.qvw at the timestamp seen in the Webserver logs.
3. Using the above, get the CPU and VMFree information to see what decision is being made. 

Example: "Loaded Document"

In the below example we can see that SOME-SERVER-1 already has SOMEDOC.QVW loaded (loaded: True) so it will be loaded there due to the load balancing rule. This server does also have more VM free and CPU free as well, so hypothetically if the document were already loaded on both SOME-SERVER-1 and also SOME-SERVER-2 then it would load balance to SOME-SERVER-1 in that case.

Webserver Logs:

20180327T153123.150+0300    Information    LoadBalancing - doc: UserDocuments\SOMEDOC.QVW
20180327T153123.150+0300    Information    Sending to 'SOME-SERVER-1:4747': <Global method="GetUtilizationData"></Global>
20180327T153123.150+0300    Information    Sending to 'SOME-SERVER-2:4747': <Global method="GetUtilizationData"></Global>
20180327T153123.150+0300    Information    Received from 'SOME-SERVER-1:4747': <Global><UtilizationData>...</UtilizationData></Global>
20180327T153123.150+0300    Information    Received from 'SOME-SERVER-2:4747': <Global><UtilizationData>...</UtilizationData></Global>
20180327T153123.197+0300    Information    Qvs name: SOME-SERVER-1 loaded: True VMFree: 37000.568714
20180327T153123.244+0300    Information    Qvs name: SOME-SERVER-2 loaded: False VMFree: 33000.987663
20180327T153123.244+0300    Information    LoadBalancing - selected Qvs: SOME-SERVER-1

Utilization Logs:

Datetime    ServerName    DocumentName    GBytesOfRamConfigured    NumberOfCores    RecentCpuPercent    RecentRamOverload
3/27/2018 3:31:23 PM    SOME-SERVER-1    UserDocuments\SOMEDOC.QVW    512.000000000    20    0    0
3/27/2018 3:31:23 PM    SOME-SERVER-2    UserDocuments\SOMEDOC.QVW    512.000000000    20    2    0

Example: "CPU with RAM Overload"

As stated in the public documentation, this option allows QlikView Web Server (QVWS) to route traffic based on two factors, (1) RAM and (2) CPU use. The node is chosen using the following criteria:

• If RAM is readily available (low) on all available nodes, choose the node with the lowest CPU use.
• If RAM is moderately used on all available nodes, choose the node with the most RAM available.

In the below 6-node QVS example, servers 5, 1, 4, 2, and 3 have a RecentRamOverload of zero. Of these, servers 5, 4, 2, and 3 have a RecentCpuPercent of zero. Server 3 is then chosen at random from servers 5, 4, 2, and 3.

Webserver Logs:

20180411T074726.977+0300                              Information     Sending to 'SOME-SERVER-1:4747': <Global method="GetUtilizationData"></Global>
20180411T074726.977+0300                              Information     Sending to 'SOME-SERVER-2:4747': <Global method="GetUtilizationData"></Global>
20180411T074726.977+0300                              Information     Sending to 'SOME-SERVER-3:4747': <Global method="GetUtilizationData"></Global>
20180411T074726.977+0300                              Information     Sending to 'SOME-SERVER-4:4747': <Global method="GetUtilizationData"></Global>
20180411T074726.977+0300                              Information     Sending to 'SOME-SERVER-5:4747': <Global method="GetUtilizationData"></Global>
20180411T074726.977+0300                              Information     Sending to 'SOME-SERVER-6:4747': <Global method="GetUtilizationData"></Global>
20180411T074726.977+0300                              Information     Received from 'SOME-SERVER-5:4747': <Global><UtilizationData>
    <GBytesOfRamConfigured>537.324842834</GBytesOfRamConfigured>
        <NumberOfCores>24</NumberOfCores>
        <RecentCpuPercent>0</RecentCpuPercent>
        <RecentRamOverload>0</RecentRamOverload>
        <OffDuty>false</OffDuty>
        <Unlicensed>false</Unlicensed>
        <Free></Free>
        <DocIsLoaded>false</DocIsLoaded>
    </UtilizationData></Global>
20180411T074726.977+0300                              Information     Received from 'SOME-SERVER-6:4747': <Global><UtilizationData>
    <GBytesOfRamConfigured>537.324842834</GBytesOfRamConfigured>
        <NumberOfCores>24</NumberOfCores>
        <RecentCpuPercent>0</RecentCpuPercent>
        <RecentRamOverload>20</RecentRamOverload>
        <OffDuty>false</OffDuty>
        <Unlicensed>false</Unlicensed>
        <Free></Free>
        <DocIsLoaded>false</DocIsLoaded>
    </UtilizationData></Global>
20180411T074726.977+0300                              Information     Received from 'SOME-SERVER-1:4747': <Global><UtilizationData>
    <GBytesOfRamConfigured>537.41841774</GBytesOfRamConfigured>
    <NumberOfCores>24</NumberOfCores>
    <RecentCpuPercent>6</RecentCpuPercent>
    <RecentRamOverload>0</RecentRamOverload>
    <OffDuty>false</OffDuty>
    <Unlicensed>false</Unlicensed>
    <Free></Free>
    <DocIsLoaded>false</DocIsLoaded>
    </UtilizationData></Global>
20180411T074726.977+0300                              Information     Received from 'SOME-SERVER-4:4747': <Global><UtilizationData>
    <GBytesOfRamConfigured>537.418412399</GBytesOfRamConfigured>
    <NumberOfCores>24</NumberOfCores>
    <RecentCpuPercent>0</RecentCpuPercent>
    <RecentRamOverload>0</RecentRamOverload>
    <OffDuty>false</OffDuty>
    <Unlicensed>false</Unlicensed>
    <Free></Free>
    <DocIsLoaded>false</DocIsLoaded>
    </UtilizationData></Global>
20180411T074726.977+0300                              Information     Received from 'SOME-SERVER-2:4747': <Global><UtilizationData>
    <GBytesOfRamConfigured>537.41842041</GBytesOfRamConfigured>
    <NumberOfCores>24</NumberOfCores>
    <RecentCpuPercent>0</RecentCpuPercent>
    <RecentRamOverload>0</RecentRamOverload>
    <OffDuty>false</OffDuty>
    <Unlicensed>false</Unlicensed>
    <Free></Free>
    <DocIsLoaded>false</DocIsLoaded>
    </UtilizationData></Global>
20180411T074726.977+0300                              Information     Received from 'SOME-SERVER-3:4747': <Global><UtilizationData>
    <GBytesOfRamConfigured>537.418497848</GBytesOfRamConfigured>
    <NumberOfCores>24</NumberOfCores>
    <RecentCpuPercent>0</RecentCpuPercent>
    <RecentRamOverload>0</RecentRamOverload>
    <OffDuty>false</OffDuty>
    <Unlicensed>false</Unlicensed>
    <Free></Free>
    <DocIsLoaded>false</DocIsLoaded>
    </UtilizationData></Global>
20180411T074726.977+0300                              Information     Create client: 
    Mode=Authenticate, 
    Host=SOME-SERVER-3:4747, 
    ClientIP=10.20.30.40, 
    MachineId=12345678-abcd-efgh-1423-987654321abc, 
    Slot=

Utilization Logs:

Datetime    ServerName    DocumentName    GBytesOfRamConfigured    NumberOfCores    RecentCpuPercent    RecentRamOverload
4/11/2018 7:47:26 AM    SOME-SERVER-5    UserDocuments\SOMEDOC.QVW    537.324842834    24    0    0
4/11/2018 7:47:26 AM    SOME-SERVER-6    UserDocuments\SOMEDOC.QVW    537.324842834    24    0    20
4/11/2018 7:47:26 AM    SOME-SERVER-1    UserDocuments\SOMEDOC.QVW    537.41841774    24    6    0
4/11/2018 7:47:26 AM    SOME-SERVER-4    UserDocuments\SOMEDOC.QVW    537.418412399    24    0    0
4/11/2018 7:47:26 AM    SOME-SERVER-2    UserDocuments\SOMEDOC.QVW    537.41842041    24    0    0
4/11/2018 7:47:26 AM    SOME-SERVER-3    UserDocuments\SOMEDOC.QVW    537.418497848    24    0    0