[Bug]: Severe performance degradation after upgrading from 1.1.4 to 1.2.0

[StijnvanderLippe]

What happened?

After upgrading to version 1.2.0 of the Python package, I've noticed severely increased runtimes for loading data from Delta tables in Azure Blob Storage. Version 1.1.4 works as expected.

I've ran a profiler on the code. The logs show increased runtimes for

• {method 'dataset_partitions' of 'deltalake._internal.RawDeltaTable' objects}
• {method 'get_add_file_sizes' of 'deltalake._internal.RawDeltaTable' objects}

Looking through the commit history, I've narrowed it down to changes made in one of these commits:

• 22aa7cb
• c283bde
• 699aa9a
• 8ebe4dd

Expected behavior

Loading data from Delta tables should not be significantly slower between versions without clear indicators why this would be the case.

Operating System

Linux

Binding

Python

Bindings Version

1.2.0

Steps to reproduce

The data in question is partitioned by NAME. Additionally, I filter on the timestamp of the datapoints in the TS column. I have several partitions I need to fetch, which I manually loop over. I know you can fetch all the desired partitions in one go, but this manual looping is necessary since not all the data fits in memory at the same time on the system running this code. Hence, I need to fetch one partition at a time, do some post-processing and store the processed results, before fetching the next partition.

I've extracted the core parts of the data loading into the script below. Certain parts are missing but these have no effect on the impacted methods.

from azure.identity import DefaultAzureCredential
from deltalake import DeltaTable
from pyarrow.compute import field

credential = DefaultAzureCredential()

table_uri = f"abfss://{container_name}@{storage_account}.dfs.core.windows.net{path}"
delta_token = credential.get_token("https://storage.azure.com/").token
table = DeltaTable(table_uri, storage_options={"token": delta_token}, version=version)

# Manual loop over the partitions
partitions_to_fetch = [...]
for partition in partitions_to_fetch:
    partitions = [("NAME", "in", partition)]
    filters = (field("TS") >= start_date) & (field("TS") <= end_date)
    df = delta_table.to_pandas(partitions=partitions, columns=columns, filters=filters)

Commit 8ebe4dd:

         2481571 function calls (2424416 primitive calls) in 136.858 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        9   76.127    8.459   76.127    8.459 {method 'get_add_file_sizes' of 'deltalake._internal.RawDeltaTable' objects}
        9   29.083    3.231   29.436    3.271 {method 'dataset_partitions' of 'deltalake._internal.RawDeltaTable' objects}
        2   17.537    8.769   17.537    8.769 table.py:138(__init__)
        9    4.803    0.534  111.266   12.363 table.py:960(to_pyarrow_table)

Commit 7b9f2f8:

         2482108 function calls (2424944 primitive calls) in 38.173 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        2   19.285    9.643   19.285    9.643 table.py:138(__init__)
        9    4.611    0.512   11.245    1.249 table.py:910(to_pyarrow_table)
        9    3.002    0.334    3.356    0.373 {method 'dataset_partitions' of 'deltalake._internal.RawDeltaTable' objects}
        9    2.349    0.261    2.349    0.261 {method 'get_add_file_sizes' of 'deltalake._internal.RawDeltaTable' objects}
        9    0.801    0.089    0.801    0.089 {built-in method from_table}

Note the significant differences for the lines {method 'dataset_partitions' of 'deltalake._internal.RawDeltaTable' objects} and {method 'get_add_file_sizes' of 'deltalake._internal.RawDeltaTable' objects}

Relevant logs

[rtyler]

If it is not too much trouble to try again with the 1`.3.0 release that would be really helpful. We had a number of fixes that should have helped but I cannot think of something that would have directly positively impacted this 🤔

[StijnvanderLippe]

If it is not too much trouble to try again with the 1`.3.0 release that would be really helpful. We had a number of fixes that should have helped but I cannot think of something that would have directly positively impacted this 🤔

Version 1.3.0 is definitely faster than version 1.2.0, but still not as quick as version 1.1.0.

Version 1.3.0

         2532209 function calls (2475138 primitive calls) in 46.494 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        9   14.400    1.600   14.400    1.600 {method 'get_add_file_sizes' of 'deltalake._internal.RawDeltaTable' objects}
        9   14.022    1.558   14.359    1.595 {method 'dataset_partitions' of 'deltalake._internal.RawDeltaTable' objects}
        9    4.981    0.553   34.596    3.844 table.py:928(to_pyarrow_table)
        2    4.347    2.174    4.347    2.174 table.py:136(__init__)
        9    0.708    0.079    0.708    0.079 {built-in method from_table}

Version 1.2.0

         2536037 function calls (2478867 primitive calls) in 146.447 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        9   81.526    9.058   81.526    9.058 {method 'get_add_file_sizes' of 'deltalake._internal.RawDeltaTable' objects}
        9   32.060    3.562   32.378    3.598 {method 'dataset_partitions' of 'deltalake._internal.RawDeltaTable' objects}
        2   18.828    9.414   18.828    9.414 table.py:138(__init__)
        9    5.155    0.573  120.183   13.354 table.py:933(to_pyarrow_table)
        9    0.977    0.109    0.977    0.109 {built-in method from_table}

Version 1.1.0

         2548865 function calls (2491701 primitive calls) in 25.913 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        9    5.777    0.642   14.259    1.584 table.py:905(to_pyarrow_table)
        2    4.087    2.043    4.087    2.043 table.py:138(__init__)
        9    3.813    0.424    4.172    0.464 {method 'dataset_partitions' of 'deltalake._internal.RawDeltaTable' objects}
        9    3.209    0.357    3.209    0.357 {method 'get_add_file_sizes' of 'deltalake._internal.RawDeltaTable' objects}
        9    0.952    0.106    0.952    0.106 {built-in method from_table}

[ion-elgreco]

@StijnvanderLippe it would be good to also measure how long it takes to initialize a Delta table in 1.1.0 vs 1.3.0 that gives a rounder picture of what we are looking at.

@roeap it seems that accessing data using file_views is still slower than what we had before, not sure if that's due to the fact that before the state was more materialized than now

[roeap]

Would be great if we can narrow down things a bit more - i.e the to_pandas call likely goes through the dataset API?

Currently in teh process of setting up a bit more measurement to get a rounder picture. especially in this "half-state" we are in, its hard to say where the latency comes from.

THe more reference examples we have that show differences the better though :).

[rtyler]

I have some theories on where this might be coming from, I will do some investigation today as time allows 😄

[StijnvanderLippe]

@StijnvanderLippe it would be good to also measure how long it takes to initialize a Delta table in 1.1.0 vs 1.3.0 that gives a rounder picture of what we are looking at.

Do you have some example code I can use to do that? The Delta tables I use are set up by another team, I'm only a user of the data. So I don't have any experience with actually setting up a Delta table.

Or do mean "initializing" in the sense of setting up a connection to an existing Delta table?

[rtyler]

I can demonstrate the abysmal performance on the code that get_add_file_sizes() executes. This is decidedly bad performance 😆

On my test table, @roeap knows the one, there are about 30s spent opening the table where we have known performance deficiencies. Calling get_add_file_sizes() results in another 120s of single-CPU runtime. I am still parsing through the profiling results, but I think I have enough here to self-assign and dig into the problem.

[rtyler]

@StijnvanderLippe can you test with the 1.4.0 release we just cut to see if the performance is within the bounds of what you would expect?