Timing question when getting a cube

[Cubewise-gtejeda]

Below is some simple code, which gets a reference to the same cube twice after connecting. It takes around 2 seconds the first time and a split second the second time. Trying to figure out why that is:

TM1py version: 2.0.2
PA version: 11.8.01900.10

Code:

from TM1py.Services import TM1Service
import time


def timing():
    address = 'localhost'
    port = 12354
    user = 'admin'
    password = 'apple'
    cube = "plan_budgetPlan"

    with TM1Service(
        address=address,
        port=port,
        user=user,
        password=password
    ) as tm1:
        now = time.time()
        t = tm1.cubes.get(cube)
        print(time.time() - now)
        now = time.time()
        t = tm1.cubes.get(cube)
        print(time.time() - now)


if __name__ == "__main__":
    timing()

Output:

2.081879138946533
0.0020101070404052734

[bdunleavy22]

To add to this, the same is true for the "tm1.server.get_data_directory()" function

[MariusWirtz]

Fascinating.
Is this some kind of server-side caching we weren't aware of?

I'm pretty sure that the requests library we use in Python doesn't do caching implicitly.

EDIT:
it's not caching. The first request has a kind of 2 sec delay. It gets more obvious when requests 1 and 2 request different stuff.

from TM1py.Services import TM1Service
import time


def timing():
    address = 'localhost'
    port = 12354
    user = 'admin'
    password = 'apple'

    with TM1Service(
        address=address,
        port=port,
        user=user,
        password=password
    ) as tm1:
        now = time.time()
        t = tm1.server.get_server_name()
        print(time.time() - now)

        for _ in range(4):
            now = time.time()
            t = tm1.server.get_product_version()
            print(time.time() - now)


if __name__ == "__main__":
    timing()

[macsir]

What TM1 version is it? Get Outlook for iOS<https://aka.ms/o0ukef>

…

________________________________ From: Marius Wirtz ***@***.***> Sent: Friday, April 5, 2024 4:43:51 AM To: cubewise-code/tm1py ***@***.***> Cc: Subscribed ***@***.***> Subject: Re: [cubewise-code/tm1py] Timing question when getting a cube (Discussion #1093) Fascinating. Is this some kind of server-side caching we weren't aware of? I'm pretty sure that the requests library we use in Python doesn't do caching implicitly — Reply to this email directly, view it on GitHub<#1093 (comment)>, or unsubscribe<https://github.com/notifications/unsubscribe-auth/AAZQV7P5D7MOE3KUXR7ZVLLY3WNOPAVCNFSM6AAAAABFXZAMD6VHI2DSMVQWIX3LMV43SRDJONRXK43TNFXW4Q3PNVWWK3TUHM4TAMJTGM4TQ>. You are receiving this because you are subscribed to this thread.Message ID: ***@***.***>

[rclapp]

I guess next steps would be a test with curl or postman?

[bdunleavy22]

I did a bit of googling and found this: https://stackoverflow.com/questions/54078692/why-first-network-call-takes-more-time-than-subsequent-ones
Someone having the same issue with a different API. I would guess the relevant part of the answer for our case would be "Making initial connection handshake to the server is taking time (DNS Lookup + Initial connection + SSL). Browsers are creating Persistent Connections for HTTP requests and keep it open for some time. If any request came in for the same domain within that time, the browser will try to reuse the same connection for faster response."
I don't know how to check/verify this, but I would not be surprised if there was an initial handshake which includes a verification process that subsequent requests do not do once the connection has been established.

[rclapp]

There maybe some python network profiling tools we could use. From: bennybooo22 ***@***.***> Reply-To: cubewise-code/tm1py ***@***.***> Date: Friday, April 5, 2024 at 11:17 AM To: cubewise-code/tm1py ***@***.***> Cc: "Clapp, Ryan" ***@***.***>, Comment ***@***.***> Subject: Re: [cubewise-code/tm1py] Timing question when getting a cube (Discussion #1093) I did a bit of googling and found this: https://stackoverflow.com/questions/54078692/why-first-network-call-takes-more-time-than-subsequent-ones Someone having the same issue with a different API. I would guess the relevant part of the answer for our case would be "Making initial connection handshake to the server is taking time (DNS Lookup + Initial connection + SSL). Browsers are creating Persistent Connections for HTTP requests and keep it open for some time. If any request came in for the same domain within that time, the browser will try to reuse the same connection for faster response." I don't know how to check/verify this, but I would not be surprised if there was an initial handshake which includes a verification process that subsequent requests do not do once the connection has been established. — Reply to this email directly, view it on GitHub<#1093 (comment)>, or unsubscribe<https://github.com/notifications/unsubscribe-auth/AEK7GZSHINIBNXH5Y4QTJTTY32573AVCNFSM6AAAAABFXZAMD6VHI2DSMVQWIX3LMV43SRDJONRXK43TNFXW4Q3PNVWWK3TUHM4TAMRSHE3DE>. You are receiving this because you commented.Message ID: ***@***.***>

[Cubewise-gtejeda]

Did some more investigation and testing on this with the team and have some interesting findings:

We compared the timing between a PA Cloud TM1 instance and a local TM1 instance and the local instance was consistently slower:

The type of call is not important for this context.

Measured locally (response time in seconds):

2.122556447982788
2.046565532684326
4.095233678817749

Measured locally (response time in seconds):

0.5757761001586914
0.1015176773071289
0.20470976829528809

Quite a significant difference here.

For the local test it was using a the localhost reference in the tm1params.
After changing this to 127.0.0.1 instead, the response times are more in line with the expectation (should be faster locally, no?):

0.008466005325317383
0.002999544143676758
0.007999897003173828

The loopback address (127.0.0.1) is always available, so you don't have to rely on a specific IP address. Using the configured IP address produces similar results as compared to the loopback address, but is less reliable, since IP addresses can change in a DHCP based environment.

Additional findings:
It was commented online that the IPv6 lookup for localhost can cause a timeout delay in some circumstances.

Adding the lines below whilst using localhost produces similar results to when using the loopback adapter:

import requests
requests.packages.urllib3.util.connection.HAS_IPV6 = False

Results:

0.01405644416809082
0.003710508346557617
0.008528470993041992

Please feel free to comment in case more detail is needed.

Cheers!