diff --git a/CHANGELOG.md b/CHANGELOG.md index bce9e16e4..8e1dd505f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,8 @@ # Release History +# Unreleased +- Fix: a CloudFetch download that finished faster than the clock resolution (common on Windows) no longer fails the fetch with `ZeroDivisionError` while logging its download speed. Download time is now measured with `time.perf_counter()`. + # 4.6.0 (2026-09-24) - Upgrade Databricks SQL Kernel to 1.1.0; the kernel dependency is now stable and no longer experimental. - Transparently auto-recover Thrift connections to Reyden / Real-Time warehouses: when a warehouse rejects the default Thrift protocol (SQLSTATE `KP001`), the session is re-opened on the kernel backend and the warehouse is remembered so later connections skip Thrift. Applies only when no backend was chosen explicitly. diff --git a/src/databricks/sql/cloudfetch/downloader.py b/src/databricks/sql/cloudfetch/downloader.py index 295f147cd..a9db6e754 100644 --- a/src/databricks/sql/cloudfetch/downloader.py +++ b/src/databricks/sql/cloudfetch/downloader.py @@ -100,7 +100,7 @@ def run(self) -> DownloadedFile: self.link, self.settings.link_expiry_buffer_secs ) - start_time = time.time() + start_time = time.perf_counter() with self._http_client.request_context( method=HttpMethod.GET, @@ -113,7 +113,7 @@ def run(self) -> DownloadedFile: compressed_data = response.data # Log download metrics - download_duration = time.time() - start_time + download_duration = time.perf_counter() - start_time self._log_download_metrics( self.link.fileLink, len(compressed_data), download_duration ) @@ -148,8 +148,13 @@ def _log_download_metrics( self, url: str, bytes_downloaded: int, duration_seconds: float ): """Log download speed metrics at INFO/WARN levels.""" - # Calculate speed in MB/s (ensure float division for precision) - speed_mbps = (float(bytes_downloaded) / (1024 * 1024)) / duration_seconds + # Calculate speed in MB/s (ensure float division for precision). A download + # that finishes within the clock resolution has no measurable duration. + speed_mbps = ( + (float(bytes_downloaded) / (1024 * 1024)) / duration_seconds + if duration_seconds > 0 + else float("inf") + ) urlEndpoint = url.split("?")[0] # INFO level logging diff --git a/tests/unit/test_downloader.py b/tests/unit/test_downloader.py index 00b1b849a..60bb36fdd 100644 --- a/tests/unit/test_downloader.py +++ b/tests/unit/test_downloader.py @@ -179,6 +179,39 @@ def test_run_compressed_successful(self, mock_time): self.assertEqual(file.start_row_offset, result_link.startRowOffset) self.assertEqual(file.row_count, result_link.rowCount) + @patch("time.perf_counter", return_value=50.0) + @patch("time.time", return_value=1000) + def test_run_successful_when_clock_does_not_advance( + self, mock_time, mock_perf_counter + ): + # A download that finishes within one clock tick has a measured duration of 0 + mock_http_client = MagicMock() + file_bytes = b"1234567890" * 10 + settings = Mock(link_expiry_buffer_secs=0, download_timeout=0, use_proxy=False) + settings.is_lz4_compressed = False + settings.min_cloudfetch_download_speed = 0.1 + result_link = Mock(expiryTime=1001, bytesNum=len(file_bytes)) + result_link.fileLink = "https://s3.amazonaws.com/bucket/file.arrow?token=xyz789" + self._setup_mock_http_response(mock_http_client, status=200, data=file_bytes) + + d = downloader.ResultSetDownloadHandler( + settings, + result_link, + ssl_options=SSLOptions(), + chunk_id=0, + session_id_hex=Mock(), + statement_id=Mock(), + http_client=mock_http_client, + ) + with self.assertLogs(downloader.logger, level="INFO") as logs: + file = d.run() + + self.assertEqual(file.file_bytes, file_bytes) + self.assertEqual(file.start_row_offset, result_link.startRowOffset) + self.assertEqual(file.row_count, result_link.rowCount) + self.assertEqual([r.levelname for r in logs.records], ["INFO"]) + self.assertIn("CloudFetch download completed", logs.records[0].getMessage()) + @patch("time.time", return_value=1000) def test_download_connection_error(self, mock_time): mock_http_client = MagicMock()