strange behaviour with CloudFetch

Inizia dagli entry point CloudFetchQueue, ResultFileDownloadManager, ResultSetDownloadHandler e FetchResults indicati nel log di debug, quindi riproduci la query Azure Databricks di grandi dimensioni. Traccia la transizione all’offset dell’ultima riga e verifica che il recupero completo dei risultati termini senza l’avviso segnalato relativo a un file mancante né ritardi inspiegabili.

Hi,

i have created a small python-script to fetch data from the sql-endpoint in azure databricks. The queried view has 2126641 rows. As you can see, CloudFetch serves batches as files as expected. Also the performance and data-throughput is very good until this line:

2024-11-27 05:35:22,038 - DEBUG - CloudFetchQueue: Cannot find downloaded file for row 2126641

It tries to fetch a file for the last position, what fails. After that, there is obviously a gap of 22 seconds, where seemingly nothing happens. When monitoring the network-traffic, you can see that until that point, i have full throughput of my internet-connection. After this point, nearly no more network-activity until the connection was closed. I did this test, because i experienced a similar behaviour over a ODBC-Connection with Simba Spark-Driver, where also CloudFetch should be used. So i am not sure if this behaviour is special to the API-Connection and databricks-sql-connector or if this is a general problem with CloudFetch or if this is intended and why it should be?
Any thoughts about this?

tested with databricks-sql-connector 3.6 and python 3.9 as well as with python 3.12.5.

2024-11-27 05:35:08,235 - INFO - Starting Databricks SQL query... 2024-11-27 05:35:09,821 - DEBUG - retry parameter: _retry_delay_min given_or_default 1.0 2024-11-27 05:35:09,821 - DEBUG - retry parameter: _retry_delay_max given_or_default 60.0 2024-11-27 05:35:09,821 - DEBUG - retry parameter: _retry_stop_after_attempts_count given_or_default 30 2024-11-27 05:35:09,821 - DEBUG - retry parameter: _retry_stop_after_attempts_duration given_or_default 900.0 2024-11-27 05:35:09,821 - DEBUG - retry parameter: _retry_delay_default given_or_default 5.0 2024-11-27 05:35:09,824 - DEBUG - Sending request: OpenSession(<REDACTED>) 2024-11-27 05:35:09,824 - DEBUG - Starting new HTTPS connection (1): <REDACTED>.azuredatabricks.net:443 2024-11-27 05:35:10,212 - DEBUG - https://<REDACTED>.azuredatabricks.net:443 "POST /sql/1.0/warehouses/<REDACTED> HTTP/1.1" 200 None 2024-11-27 05:35:10,213 - DEBUG - Received response: TOpenSessionResp(<REDACTED>) 2024-11-27 05:35:10,213 - INFO - Successfully opened session 01efac78-fc58-1b8c-b7bd-06ce90e9b72f 2024-11-27 05:35:10,213 - DEBUG - Executing query: SELECT * FROM apteco.src.at_kunden-aktionen 2024-11-27 05:35:10,213 - DEBUG - Sending request: ExecuteStatement(<REDACTED>) 2024-11-27 05:35:11,530 - DEBUG - https://<REDACTED>.azuredatabricks.net:443 "POST /sql/1.0/warehouses/<REDACTED> HTTP/1.1" 200 None 2024-11-27 05:35:11,538 - DEBUG - Received response: TExecuteStatementResp(<REDACTED>) 2024-11-27 05:35:11,539 - DEBUG - Initialize CloudFetch loader, row set start offset: 0, file list: 2024-11-27 05:35:11,539 - DEBUG - - start row offset: 0, row count: 110592 2024-11-27 05:35:11,539 - DEBUG - - start row offset: 110592, row count: 77136 2024-11-27 05:35:11,539 - DEBUG - - start row offset: 187728, row count: 110592 2024-11-27 05:35:11,539 - DEBUG - - start row offset: 298320, row count: 110592 2024-11-27 05:35:11,539 - DEBUG - - start row offset: 408912, row count: 110592 2024-11-27 05:35:11,539 - DEBUG - ResultFileDownloadManager: adding file link, start offset 0, row count: 110592 2024-11-27 05:35:11,539 - DEBUG - ResultFileDownloadManager: adding file link, start offset 110592, row count: 77136 2024-11-27 05:35:11,539 - DEBUG - ResultFileDownloadManager: adding file link, start offset 187728, row count: 110592 2024-11-27 05:35:11,539 - DEBUG - ResultFileDownloadManager: adding file link, start offset 298320, row count: 110592 2024-11-27 05:35:11,539 - DEBUG - ResultFileDownloadManager: adding file link, start offset 408912, row count: 110592 2024-11-27 05:35:11,539 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 0 2024-11-27 05:35:11,539 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:11,539 - DEBUG - - start: 0, row count: 110592 2024-11-27 05:35:11,540 - DEBUG - ResultSetDownloadHandler: starting file download, offset 0, row count 110592 2024-11-27 05:35:11,540 - DEBUG - - start: 110592, row count: 77136 2024-11-27 05:35:11,541 - DEBUG - ResultSetDownloadHandler: starting file download, offset 110592, row count 77136 2024-11-27 05:35:11,541 - DEBUG - - start: 187728, row count: 110592 2024-11-27 05:35:11,543 - DEBUG - ResultSetDownloadHandler: starting file download, offset 187728, row count 110592 2024-11-27 05:35:11,544 - DEBUG - - start: 298320, row count: 110592 2024-11-27 05:35:11,544 - DEBUG - ResultSetDownloadHandler: starting file download, offset 298320, row count 110592 2024-11-27 05:35:11,544 - DEBUG - - start: 408912, row count: 110592 2024-11-27 05:35:11,547 - DEBUG - Starting new HTTPS connection (1): <REDACTED>.blob.core.windows.net:443 2024-11-27 05:35:11,548 - DEBUG - Starting new HTTPS connection (1): <REDACTED>.blob.core.windows.net:443 2024-11-27 05:35:11,549 - DEBUG - Starting new HTTPS connection (1): <REDACTED>.blob.core.windows.net:443 2024-11-27 05:35:11,550 - DEBUG - Starting new HTTPS connection (1): <REDACTED>.blob.core.windows.net:443 2024-11-27 05:35:11,551 - DEBUG - ResultSetDownloadHandler: starting file download, offset 408912, row count 110592 2024-11-27 05:35:11,553 - DEBUG - Starting new HTTPS connection (1): <REDACTED>.blob.core.windows.net:443 2024-11-27 05:35:12,085 - DEBUG - https://<REDACTED>.blob.core.windows.net:443 "GET /jobs/7551410669527543/sql/2024-11-27/03/results_2024-11-27T03:50:13Z_0841d744-5100-492c-90b5-f6df3c75cd28?sig=<REDACTED>&se=<REDACTED>&sv=<REDACTED>&spr=<REDACTED>&sp=<REDACTED>&sr=<REDACTED> HTTP/1.1" 200 9596381 2024-11-27 05:35:12,088 - DEBUG - https://<REDACTED>.blob.core.windows.net:443 "GET /jobs/7551410669527543/sql/2024-11-27/03/results_2024-11-27T03:50:14Z_27728922-8a08-4e33-9855-350ef4e99397?sig=<REDACTED>&se=<REDACTED>&sv=<REDACTED>&spr=<REDACTED>&sp=<REDACTED>&sr=<REDACTED> HTTP/1.1" 200 6690419 2024-11-27 05:35:12,105 - DEBUG - https://<REDACTED>.blob.core.windows.net:443 "GET /jobs/7551410669527543/sql/2024-11-27/03/results_2024-11-27T03:50:14Z_408d6edd-64e3-4a00-b735-46f67958d59f?sig=<REDACTED>&se=<REDACTED>&sv=<REDACTED>&spr=<REDACTED>&sp=<REDACTED>&sr=<REDACTED> HTTP/1.1" 200 10095071 2024-11-27 05:35:12,111 - DEBUG - https://<REDACTED>.blob.core.windows.net:443 "GET /jobs/7551410669527543/sql/2024-11-27/03/results_2024-11-27T03:50:14Z_44fba0fb-35df-483e-8414-e336493e9da7?sig=<REDACTED>&se=<REDACTED>&sv=<REDACTED>&spr=<REDACTED>&sp=<REDACTED>&sr=<REDACTED> HTTP/1.1" 200 10099743 2024-11-27 05:35:12,145 - DEBUG - https://<REDACTED>.blob.core.windows.net:443 "GET /jobs/7551410669527543/sql/2024-11-27/03/results_2024-11-27T03:50:13Z_2dd105bf-c426-4035-86bc-a54868d98f71?sig=<REDACTED>&se=<REDACTED>&sv=<REDACTED>&spr=<REDACTED>&sp=<REDACTED>&sr=<REDACTED> HTTP/1.1" 200 10099510 2024-11-27 05:35:13,448 - DEBUG - ResultSetDownloadHandler: successfully downloaded file, offset 0, row count 110592 2024-11-27 05:35:13,466 - DEBUG - CloudFetchQueue: Found downloaded file, row count: 110592, new start offset: 110592 2024-11-27 05:35:13,468 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 110592 2024-11-27 05:35:13,468 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:13,637 - DEBUG - ResultSetDownloadHandler: successfully downloaded file, offset 110592, row count 77136 2024-11-27 05:35:13,639 - DEBUG - CloudFetchQueue: Found downloaded file, row count: 77136, new start offset: 187728 2024-11-27 05:35:13,641 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 187728 2024-11-27 05:35:13,642 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:13,761 - DEBUG - ResultSetDownloadHandler: successfully downloaded file, offset 408912, row count 110592 2024-11-27 05:35:13,947 - DEBUG - ResultSetDownloadHandler: successfully downloaded file, offset 298320, row count 110592 2024-11-27 05:35:14,369 - DEBUG - ResultSetDownloadHandler: successfully downloaded file, offset 187728, row count 110592 2024-11-27 05:35:14,371 - DEBUG - CloudFetchQueue: Found downloaded file, row count: 110592, new start offset: 298320 2024-11-27 05:35:14,372 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 298320 2024-11-27 05:35:14,372 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:14,373 - DEBUG - CloudFetchQueue: Found downloaded file, row count: 110592, new start offset: 408912 2024-11-27 05:35:14,373 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 408912 2024-11-27 05:35:14,373 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:14,374 - DEBUG - CloudFetchQueue: Found downloaded file, row count: 110592, new start offset: 519504 2024-11-27 05:35:14,374 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 519504 2024-11-27 05:35:14,374 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:14,374 - DEBUG - CloudFetchQueue: Cannot find downloaded file for row 519504 2024-11-27 05:35:14,375 - DEBUG - Sending request: FetchResults(<REDACTED>) 2024-11-27 05:35:14,488 - DEBUG - https://<REDACTED>.azuredatabricks.net:443 "POST /sql/1.0/warehouses/<REDACTED> HTTP/1.1" 200 None 2024-11-27 05:35:14,494 - DEBUG - Received response: TFetchResultsResp(<REDACTED>) 2024-11-27 05:35:14,494 - DEBUG - Initialize CloudFetch loader, row set start offset: 519504, file list: 2024-11-27 05:35:14,494 - DEBUG - - start row offset: 519504, row count: 38765 2024-11-27 05:35:14,494 - DEBUG - - start row offset: 558269, row count: 82979 2024-11-27 05:35:14,494 - DEBUG - - start row offset: 641248, row count: 110592 2024-11-27 05:35:14,494 - DEBUG - - start row offset: 751840, row count: 94279 2024-11-27 05:35:14,494 - DEBUG - - start row offset: 846119, row count: 110592 2024-11-27 05:35:14,494 - DEBUG - - start row offset: 956711, row count: 11559 2024-11-27 05:35:14,495 - DEBUG - ResultFileDownloadManager: adding file link, start offset 519504, row count: 38765 2024-11-27 05:35:14,495 - DEBUG - ResultFileDownloadManager: adding file link, start offset 558269, row count: 82979 2024-11-27 05:35:14,495 - DEBUG - ResultFileDownloadManager: adding file link, start offset 641248, row count: 110592 2024-11-27 05:35:14,495 - DEBUG - ResultFileDownloadManager: adding file link, start offset 751840, row count: 94279 2024-11-27 05:35:14,495 - DEBUG - ResultFileDownloadManager: adding file link, start offset 846119, row count: 110592 2024-11-27 05:35:14,495 - DEBUG - ResultFileDownloadManager: adding file link, start offset 956711, row count: 11559 2024-11-27 05:35:14,495 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 519504 2024-11-27 05:35:14,495 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:14,495 - DEBUG - - start: 519504, row count: 38765 2024-11-27 05:35:14,495 - DEBUG - ResultSetDownloadHandler: starting file download, offset 519504, row count 38765 2024-11-27 05:35:14,495 - DEBUG - - start: 558269, row count: 82979 2024-11-27 05:35:14,496 - DEBUG - ResultSetDownloadHandler: starting file download, offset 558269, row count 82979 2024-11-27 05:35:14,497 - DEBUG - - start: 641248, row count: 110592 2024-11-27 05:35:14,498 - DEBUG - Starting new HTTPS connection (1): <REDACTED>.blob.core.windows.net:443 2024-11-27 05:35:14,498 - DEBUG - ResultSetDownloadHandler: starting file download, offset 641248, row count 110592 2024-11-27 05:35:14,499 - DEBUG - - start: 751840, row count: 94279 2024-11-27 05:35:14,499 - DEBUG - Starting new HTTPS connection (1): <REDACTED>.blob.core.windows.net:443 2024-11-27 05:35:14,500 - DEBUG - ResultSetDownloadHandler: starting file download, offset 751840, row count 94279 2024-11-27 05:35:14,501 - DEBUG - Starting new HTTPS connection (1): <REDACTED>.blob.core.windows.net:443 2024-11-27 05:35:14,501 - DEBUG - - start: 846119, row count: 110592 2024-11-27 05:35:14,503 - DEBUG - Starting new HTTPS connection (1): <REDACTED>.blob.core.windows.net:443 2024-11-27 05:35:14,503 - DEBUG - ResultSetDownloadHandler: starting file download, offset 846119, row count 110592 2024-11-27 05:35:14,503 - DEBUG - - start: 956711, row count: 11559 2024-11-27 05:35:14,505 - DEBUG - Starting new HTTPS connection (1): <REDACTED>.blob.core.windows.net:443 2024-11-27 05:35:14,505 - DEBUG - ResultSetDownloadHandler: starting file download, offset 956711, row count 11559 2024-11-27 05:35:14,506 - DEBUG - Starting new HTTPS connection (1): <REDACTED>.blob.core.windows.net:443 2024-11-27 05:35:14,748 - DEBUG - https://<REDACTED>.blob.core.windows.net:443 "GET /jobs/7551410669527543/sql/2024-11-27/03/results_2024-11-27T03:50:13Z_6fabdb84-db50-4d88-8248-21725025b495?sig=<REDACTED>&se=<REDACTED>&sv=<REDACTED>&spr=<REDACTED>&sp=<REDACTED>&sr=<REDACTED> HTTP/1.1" 200 10282750 2024-11-27 05:35:14,764 - DEBUG - https://<REDACTED>.blob.core.windows.net:443 "GET /jobs/7551410669527543/sql/2024-11-27/03/results_2024-11-27T03:50:15Z_a588537d-fb44-41de-be68-acd73b0652f2?sig=<REDACTED>&se=<REDACTED>&sv=<REDACTED>&spr=<REDACTED>&sp=<REDACTED>&sr=<REDACTED> HTTP/1.1" 200 3542569 2024-11-27 05:35:14,772 - DEBUG - https://<REDACTED>.blob.core.windows.net:443 "GET /jobs/7551410669527543/sql/2024-11-27/03/results_2024-11-27T03:50:13Z_5f83ceaa-3c17-49f6-b733-e6f981c144ca?sig=<REDACTED>&se=<REDACTED>&sv=<REDACTED>&spr=<REDACTED>&sp=<REDACTED>&sr=<REDACTED> HTTP/1.1" 200 10127499 2024-11-27 05:35:14,803 - DEBUG - https://<REDACTED>.blob.core.windows.net:443 "GET /jobs/7551410669527543/sql/2024-11-27/03/results_2024-11-27T03:50:13Z_13175d31-f5f7-4bd4-87c0-5b062af131e2?sig=<REDACTED>&se=<REDACTED>&sv=<REDACTED>&spr=<REDACTED>&sp=<REDACTED>&sr=<REDACTED> HTTP/1.1" 200 8770934 2024-11-27 05:35:14,804 - DEBUG - https://<REDACTED>.blob.core.windows.net:443 "GET /jobs/7551410669527543/sql/2024-11-27/03/results_2024-11-27T03:50:13Z_3b3a5a31-5acf-431e-a447-9439379dfc9c?sig=<REDACTED>&se=<REDACTED>&sv=<REDACTED>&spr=<REDACTED>&sp=<REDACTED>&sr=<REDACTED> HTTP/1.1" 200 1059435 2024-11-27 05:35:14,812 - DEBUG - https://<REDACTED>.blob.core.windows.net:443 "GET /jobs/7551410669527543/sql/2024-11-27/03/results_2024-11-27T03:50:13Z_e01076e7-9e64-4bf2-803e-78166cd91d8e?sig=<REDACTED>&se=<REDACTED>&sv=<REDACTED>&spr=<REDACTED>&sp=<REDACTED>&sr=<REDACTED> HTTP/1.1" 200 7583682 2024-11-27 05:35:15,488 - DEBUG - ResultSetDownloadHandler: successfully downloaded file, offset 519504, row count 38765 2024-11-27 05:35:15,490 - DEBUG - CloudFetchQueue: Found downloaded file, row count: 38765, new start offset: 558269 2024-11-27 05:35:15,490 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 558269 2024-11-27 05:35:15,491 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:15,505 - DEBUG - ResultSetDownloadHandler: successfully downloaded file, offset 956711, row count 11559 2024-11-27 05:35:16,221 - DEBUG - ResultSetDownloadHandler: successfully downloaded file, offset 641248, row count 110592 2024-11-27 05:35:16,260 - DEBUG - ResultSetDownloadHandler: successfully downloaded file, offset 846119, row count 110592 2024-11-27 05:35:16,406 - DEBUG - ResultSetDownloadHandler: successfully downloaded file, offset 558269, row count 82979 2024-11-27 05:35:16,408 - DEBUG - CloudFetchQueue: Found downloaded file, row count: 82979, new start offset: 641248 2024-11-27 05:35:16,408 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 641248 2024-11-27 05:35:16,409 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:16,409 - DEBUG - CloudFetchQueue: Found downloaded file, row count: 110592, new start offset: 751840 2024-11-27 05:35:16,410 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 751840 2024-11-27 05:35:16,410 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:16,711 - DEBUG - ResultSetDownloadHandler: successfully downloaded file, offset 751840, row count 94279 2024-11-27 05:35:16,712 - DEBUG - CloudFetchQueue: Found downloaded file, row count: 94279, new start offset: 846119 2024-11-27 05:35:16,713 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 846119 2024-11-27 05:35:16,713 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:16,713 - DEBUG - CloudFetchQueue: Found downloaded file, row count: 110592, new start offset: 956711 2024-11-27 05:35:16,714 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 956711 2024-11-27 05:35:16,714 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:16,714 - DEBUG - CloudFetchQueue: Found downloaded file, row count: 11559, new start offset: 968270 2024-11-27 05:35:16,714 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 968270 2024-11-27 05:35:16,715 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:16,715 - DEBUG - CloudFetchQueue: Cannot find downloaded file for row 968270 2024-11-27 05:35:16,715 - DEBUG - Sending request: FetchResults(<REDACTED>) 2024-11-27 05:35:16,804 - DEBUG - https://<REDACTED>.azuredatabricks.net:443 "POST /sql/1.0/warehouses/<REDACTED> HTTP/1.1" 200 None 2024-11-27 05:35:16,810 - DEBUG - Received response: TFetchResultsResp(<REDACTED>) 2024-11-27 05:35:16,810 - DEBUG - Initialize CloudFetch loader, row set start offset: 968270, file list: 2024-11-27 05:35:16,810 - DEBUG - - start row offset: 968270, row count: 109947 2024-11-27 05:35:16,810 - DEBUG - - start row offset: 1078217, row count: 134690 2024-11-27 05:35:16,810 - DEBUG - - start row offset: 1212907, row count: 134543 2024-11-27 05:35:16,811 - DEBUG - - start row offset: 1347450, row count: 138304 2024-11-27 05:35:16,811 - DEBUG - ResultFileDownloadManager: adding file link, start offset 968270, row count: 109947 2024-11-27 05:35:16,811 - DEBUG - ResultFileDownloadManager: adding file link, start offset 1078217, row count: 134690 2024-11-27 05:35:16,811 - DEBUG - ResultFileDownloadManager: adding file link, start offset 1212907, row count: 134543 2024-11-27 05:35:16,811 - DEBUG - ResultFileDownloadManager: adding file link, start offset 1347450, row count: 138304 2024-11-27 05:35:16,811 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 968270 2024-11-27 05:35:16,811 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:16,811 - DEBUG - - start: 968270, row count: 109947 2024-11-27 05:35:16,811 - DEBUG - ResultSetDownloadHandler: starting file download, offset 968270, row count 109947 2024-11-27 05:35:16,811 - DEBUG - - start: 1078217, row count: 134690 2024-11-27 05:35:16,812 - DEBUG - ResultSetDownloadHandler: starting file download, offset 1078217, row count 134690 2024-11-27 05:35:16,813 - DEBUG - - start: 1212907, row count: 134543 2024-11-27 05:35:16,813 - DEBUG - ResultSetDownloadHandler: starting file download, offset 1212907, row count 134543 2024-11-27 05:35:16,814 - DEBUG - - start: 1347450, row count: 138304 2024-11-27 05:35:16,815 - DEBUG - Starting new HTTPS connection (1): <REDACTED>.blob.core.windows.net:443 2024-11-27 05:35:16,816 - DEBUG - Starting new HTTPS connection (1): <REDACTED>.blob.core.windows.net:443 2024-11-27 05:35:16,816 - DEBUG - Starting new HTTPS connection (1): <REDACTED>.blob.core.windows.net:443 2024-11-27 05:35:16,816 - DEBUG - ResultSetDownloadHandler: starting file download, offset 1347450, row count 138304 2024-11-27 05:35:16,818 - DEBUG - Starting new HTTPS connection (1): <REDACTED>.blob.core.windows.net:443 2024-11-27 05:35:17,071 - DEBUG - https://<REDACTED>.blob.core.windows.net:443 "GET /jobs/7551410669527543/sql/2024-11-27/03/results_2024-11-27T03:50:16Z_40b06242-8d61-4cab-9790-414f3c11ed3b?sig=<REDACTED>&se=<REDACTED>&sv=<REDACTED>&spr=<REDACTED>&sp=<REDACTED>&sr=<REDACTED> HTTP/1.1" 200 11756633 2024-11-27 05:35:17,087 - DEBUG - https://<REDACTED>.blob.core.windows.net:443 "GET /jobs/7551410669527543/sql/2024-11-27/03/results_2024-11-27T03:50:13Z_2132da5e-ee5f-4d5a-88ea-fd15a3e854a9?sig=<REDACTED>&se=<REDACTED>&sv=<REDACTED>&spr=<REDACTED>&sp=<REDACTED>&sr=<REDACTED> HTTP/1.1" 200 9550729 2024-11-27 05:35:17,128 - DEBUG - https://<REDACTED>.blob.core.windows.net:443 "GET /jobs/7551410669527543/sql/2024-11-27/03/results_2024-11-27T03:50:15Z_7a2381de-e34c-4fd4-8382-348ffc717c75?sig=<REDACTED>&se=<REDACTED>&sv=<REDACTED>&spr=<REDACTED>&sp=<REDACTED>&sr=<REDACTED> HTTP/1.1" 200 11444939 2024-11-27 05:35:17,136 - DEBUG - https://<REDACTED>.blob.core.windows.net:443 "GET /jobs/7551410669527543/sql/2024-11-27/03/results_2024-11-27T03:50:15Z_7dc02dd4-48c9-4f16-91ad-324a403e075d?sig=<REDACTED>&se=<REDACTED>&sv=<REDACTED>&spr=<REDACTED>&sp=<REDACTED>&sr=<REDACTED> HTTP/1.1" 200 11476774 2024-11-27 05:35:18,126 - DEBUG - ResultSetDownloadHandler: successfully downloaded file, offset 968270, row count 109947 2024-11-27 05:35:18,129 - DEBUG - CloudFetchQueue: Found downloaded file, row count: 109947, new start offset: 1078217 2024-11-27 05:35:18,129 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 1078217 2024-11-27 05:35:18,129 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:18,589 - DEBUG - ResultSetDownloadHandler: successfully downloaded file, offset 1347450, row count 138304 2024-11-27 05:35:18,901 - DEBUG - ResultSetDownloadHandler: successfully downloaded file, offset 1078217, row count 134690 2024-11-27 05:35:18,903 - DEBUG - CloudFetchQueue: Found downloaded file, row count: 134690, new start offset: 1212907 2024-11-27 05:35:18,904 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 1212907 2024-11-27 05:35:18,904 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:19,212 - DEBUG - ResultSetDownloadHandler: successfully downloaded file, offset 1212907, row count 134543 2024-11-27 05:35:19,214 - DEBUG - CloudFetchQueue: Found downloaded file, row count: 134543, new start offset: 1347450 2024-11-27 05:35:19,215 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 1347450 2024-11-27 05:35:19,215 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:19,215 - DEBUG - CloudFetchQueue: Found downloaded file, row count: 138304, new start offset: 1485754 2024-11-27 05:35:19,216 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 1485754 2024-11-27 05:35:19,216 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:19,216 - DEBUG - CloudFetchQueue: Cannot find downloaded file for row 1485754 2024-11-27 05:35:19,217 - DEBUG - Sending request: FetchResults(<REDACTED>) 2024-11-27 05:35:19,301 - DEBUG - https://<REDACTED>.azuredatabricks.net:443 "POST /sql/1.0/warehouses/<REDACTED> HTTP/1.1" 200 None 2024-11-27 05:35:19,306 - DEBUG - Received response: TFetchResultsResp(<REDACTED>) 2024-11-27 05:35:19,307 - DEBUG - Initialize CloudFetch loader, row set start offset: 1485754, file list: 2024-11-27 05:35:19,307 - DEBUG - - start row offset: 1485754, row count: 138263 2024-11-27 05:35:19,307 - DEBUG - - start row offset: 1624017, row count: 134729 2024-11-27 05:35:19,307 - DEBUG - - start row offset: 1758746, row count: 135124 2024-11-27 05:35:19,307 - DEBUG - - start row offset: 1893870, row count: 134731 2024-11-27 05:35:19,307 - DEBUG - - start row offset: 2028601, row count: 98040 2024-11-27 05:35:19,307 - DEBUG - ResultFileDownloadManager: adding file link, start offset 1485754, row count: 138263 2024-11-27 05:35:19,307 - DEBUG - ResultFileDownloadManager: adding file link, start offset 1624017, row count: 134729 2024-11-27 05:35:19,307 - DEBUG - ResultFileDownloadManager: adding file link, start offset 1758746, row count: 135124 2024-11-27 05:35:19,307 - DEBUG - ResultFileDownloadManager: adding file link, start offset 1893870, row count: 134731 2024-11-27 05:35:19,307 - DEBUG - ResultFileDownloadManager: adding file link, start offset 2028601, row count: 98040 2024-11-27 05:35:19,307 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 1485754 2024-11-27 05:35:19,307 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:19,307 - DEBUG - - start: 1485754, row count: 138263 2024-11-27 05:35:19,308 - DEBUG - ResultSetDownloadHandler: starting file download, offset 1485754, row count 138263 2024-11-27 05:35:19,308 - DEBUG - - start: 1624017, row count: 134729 2024-11-27 05:35:19,308 - DEBUG - ResultSetDownloadHandler: starting file download, offset 1624017, row count 134729 2024-11-27 05:35:19,310 - DEBUG - - start: 1758746, row count: 135124 2024-11-27 05:35:19,310 - DEBUG - ResultSetDownloadHandler: starting file download, offset 1758746, row count 135124 2024-11-27 05:35:19,311 - DEBUG - Starting new HTTPS connection (1): <REDACTED>.blob.core.windows.net:443 2024-11-27 05:35:19,311 - DEBUG - - start: 1893870, row count: 134731 2024-11-27 05:35:19,313 - DEBUG - Starting new HTTPS connection (1): <REDACTED>.blob.core.windows.net:443 2024-11-27 05:35:19,313 - DEBUG - ResultSetDownloadHandler: starting file download, offset 1893870, row count 134731 2024-11-27 05:35:19,313 - DEBUG - Starting new HTTPS connection (1): <REDACTED>.blob.core.windows.net:443 2024-11-27 05:35:19,313 - DEBUG - - start: 2028601, row count: 98040 2024-11-27 05:35:19,315 - DEBUG - Starting new HTTPS connection (1): <REDACTED>.blob.core.windows.net:443 2024-11-27 05:35:19,315 - DEBUG - ResultSetDownloadHandler: starting file download, offset 2028601, row count 98040 2024-11-27 05:35:19,317 - DEBUG - Starting new HTTPS connection (1): <REDACTED>.blob.core.windows.net:443 2024-11-27 05:35:19,579 - DEBUG - https://<REDACTED>.blob.core.windows.net:443 "GET /jobs/7551410669527543/sql/2024-11-27/03/results_2024-11-27T03:50:17Z_06f8cf6d-7006-46cd-a082-970abb569d38?sig=<REDACTED>&se=<REDACTED>&sv=<REDACTED>&spr=<REDACTED>&sp=<REDACTED>&sr=<REDACTED> HTTP/1.1" 200 11490369 2024-11-27 05:35:19,595 - DEBUG - https://<REDACTED>.blob.core.windows.net:443 "GET /jobs/7551410669527543/sql/2024-11-27/03/results_2024-11-27T03:50:17Z_775e8acf-3bd6-4dbe-afb7-c4756050517d?sig=<REDACTED>&se=<REDACTED>&sv=<REDACTED>&spr=<REDACTED>&sp=<REDACTED>&sr=<REDACTED> HTTP/1.1" 200 11459162 2024-11-27 05:35:19,613 - DEBUG - https://<REDACTED>.blob.core.windows.net:443 "GET /jobs/7551410669527543/sql/2024-11-27/03/results_2024-11-27T03:50:16Z_b930b2f8-4320-473e-ac95-2ad11a8526df?sig=<REDACTED>&se=<REDACTED>&sv=<REDACTED>&spr=<REDACTED>&sp=<REDACTED>&sr=<REDACTED> HTTP/1.1" 200 11760370 2024-11-27 05:35:19,614 - DEBUG - https://<REDACTED>.blob.core.windows.net:443 "GET /jobs/7551410669527543/sql/2024-11-27/03/results_2024-11-27T03:50:17Z_4f5bc771-1a98-458a-aa7e-1eabc28f2a7a?sig=<REDACTED>&se=<REDACTED>&sv=<REDACTED>&spr=<REDACTED>&sp=<REDACTED>&sr=<REDACTED> HTTP/1.1" 200 8336820 2024-11-27 05:35:19,638 - DEBUG - https://<REDACTED>.blob.core.windows.net:443 "GET /jobs/7551410669527543/sql/2024-11-27/03/results_2024-11-27T03:50:16Z_b7ab8d34-e018-44c1-9bd1-4cb272e7c589?sig=<REDACTED>&se=<REDACTED>&sv=<REDACTED>&spr=<REDACTED>&sp=<REDACTED>&sr=<REDACTED> HTTP/1.1" 200 11458675 2024-11-27 05:35:21,283 - DEBUG - ResultSetDownloadHandler: successfully downloaded file, offset 2028601, row count 98040 2024-11-27 05:35:21,499 - DEBUG - ResultSetDownloadHandler: successfully downloaded file, offset 1758746, row count 135124 2024-11-27 05:35:21,741 - DEBUG - ResultSetDownloadHandler: successfully downloaded file, offset 1893870, row count 134731 2024-11-27 05:35:21,975 - DEBUG - ResultSetDownloadHandler: successfully downloaded file, offset 1485754, row count 138263 2024-11-27 05:35:21,990 - DEBUG - CloudFetchQueue: Found downloaded file, row count: 138263, new start offset: 1624017 2024-11-27 05:35:21,992 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 1624017 2024-11-27 05:35:21,992 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:22,032 - DEBUG - ResultSetDownloadHandler: successfully downloaded file, offset 1624017, row count 134729 2024-11-27 05:35:22,034 - DEBUG - CloudFetchQueue: Found downloaded file, row count: 134729, new start offset: 1758746 2024-11-27 05:35:22,035 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 1758746 2024-11-27 05:35:22,035 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:22,036 - DEBUG - CloudFetchQueue: Found downloaded file, row count: 135124, new start offset: 1893870 2024-11-27 05:35:22,036 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 1893870 2024-11-27 05:35:22,036 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:22,037 - DEBUG - CloudFetchQueue: Found downloaded file, row count: 134731, new start offset: 2028601 2024-11-27 05:35:22,037 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 2028601 2024-11-27 05:35:22,037 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:22,038 - DEBUG - CloudFetchQueue: Found downloaded file, row count: 98040, new start offset: 2126641 2024-11-27 05:35:22,038 - DEBUG - CloudFetchQueue: Trying to get downloaded file for row 2126641 2024-11-27 05:35:22,038 - DEBUG - ResultFileDownloadManager: schedule downloads 2024-11-27 05:35:22,038 - DEBUG - CloudFetchQueue: Cannot find downloaded file for row 2126641 2024-11-27 05:35:44,867 - INFO - Query Execution Time: 31.40 seconds 2024-11-27 05:35:44,868 - INFO - Total Rows Fetched: 2126641 2024-11-27 05:35:44,868 - DEBUG - Sending request: CloseOperation(<REDACTED>) 2024-11-27 05:35:45,005 - DEBUG - https://<REDACTED>.azuredatabricks.net:443 "POST /sql/1.0/warehouses/<REDACTED> HTTP/1.1" 200 None 2024-11-27 05:35:45,006 - DEBUG - Received response: TCloseOperationResp(<REDACTED>) 2024-11-27 05:35:45,006 - INFO - Closing session 01efac78-fc58-1b8c-b7bd-06ce90e9b72f 2024-11-27 05:35:45,006 - DEBUG - Sending request: CloseSession(<REDACTED>) 2024-11-27 05:35:45,078 - DEBUG - https://<REDACTED>.azuredatabricks.net:443 "POST /sql/1.0/warehouses/<REDACTED> HTTP/1.1" 200 None 2024-11-27 05:35:45,079 - DEBUG - Received response: TCloseSessionResp(<REDACTED>) 2024-11-27 05:35:45,079 - INFO - Connection closed