search

iterative / pytest-servers

Create temporary directories on the various filesystems for testing
Apache License 2.0
15 stars 4 forks source link

s3 server very slow on Windows #105

Closed rlamy closed 1 year ago

rlamy commented 1 year ago

Using the s3 server results in very long test times. I've tracked it down to aiohttp sometimes spending 2 seconds trying and failing to establish an IPv6 connection to localhost. I don't know how to solve the underlying issue, but we could workaround it by forcing IPv4 resoltion on Windows.

Reproducer:

def test_foo(tmp_upath_factory):
    src_path = tmp_upath_factory.mktemp("s3", version_aware=True)
    (src_path / "description").write_text("Cats and Dogs")
    (src_path / "cats").mkdir()
    (src_path / "cats" / "cat1").write_text("meow")
    (src_path / "cats" / "cat2").write_text("mrow")
    (src_path / "dogs").mkdir()
    (src_path / "dogs" / "dog1").write_text("woof")
    (src_path / "dogs" / "dog2").write_text("arf")
    (src_path / "dogs" / "dog3").write_text("bark")
    (src_path / "dogs" / "others").mkdir()
    (src_path / "dogs" / "others" / "dog4").write_text("ruff")

Running this test on Windows with s3fs debug logging enabled results in:

(win) PS Z:\devel\iterative\examples\windebug> pytest .\test_foo.py -s
Test session starts (platform: win32, Python 3.11.2, pytest 7.2.0, pytest-sugar 0.9.6)
benchmark: 4.0.0 (defaults: timer=time.perf_counter disable_gc=False min_rounds=5 min_time=0.000005 max_time=1.0 calibration_precision=10 warmup=False warmup_iterations=100000)
rootdir: Z:\devel\iterative\examples\windebug
plugins: asyncio-0.20.3, shutil-1.7.0, sugar-0.9.6, virtualenv-1.7.0, mock-3.8.2, hypothesis-6.68.1, servers-0.2.1.dev0+gc103d6a.d20230223, benchmark-4.0.0, cov-3.0.0
asyncio: mode=Mode.STRICT
collecting ... 
Starting a new Thread with MotoServer running on localhost:0...
2023-02-23 16:02:39,187 - s3fs - DEBUG - _upload_chunk -- Upload for <File-like object S3FileSystem, pytest-servers-bqqsgx/description>, final=True, loc=13, buffer loc=13
2023-02-23 16:02:39,187 - s3fs - DEBUG - commit -- Commit <File-like object S3FileSystem, pytest-servers-bqqsgx/description>
2023-02-23 16:02:39,187 - s3fs - DEBUG - commit -- One-shot upload of <File-like object S3FileSystem, pytest-servers-bqqsgx/description>
2023-02-23 16:02:39,187 - s3fs - DEBUG - set_session -- Setting up s3fs instance
2023-02-23 16:02:39,204 - s3fs - DEBUG - set_session -- RC: caching enabled? False (explicit option is False)
2023-02-23 16:02:39,369 - s3fs - DEBUG - _call_s3 -- CALL: put_object - ({},) - {'Key': 'description', 'Bucket': 'pytest-servers-bqqsgx', 'ACL': ''}
2023-02-23 16:02:41,444 - s3fs - DEBUG - _call_s3 -- CALL: head_object - ({},) - {'Bucket': 'pytest-servers-bqqsgx', 'Key': 'cats'}
2023-02-23 16:02:41,460 - s3fs - DEBUG - _error_wrapper -- Client error (maybe retryable): An error occurred (404) when calling the HeadObject operation: Not Found
2023-02-23 16:02:41,460 - s3fs - DEBUG - _call_s3 -- CALL: list_objects_v2 - ({},) - {'Bucket': 'pytest-servers-bqqsgx', 'Prefix': 'cats/', 'Delimiter': '/', 'MaxKeys': 1}
2023-02-23 16:02:43,518 - s3fs - DEBUG - _call_s3 -- CALL: list_objects_v2 - () - {'MaxKeys': 1, 'Bucket': 'pytest-servers-bqqsgx'}
2023-02-23 16:02:43,533 - s3fs - DEBUG - _upload_chunk -- Upload for <File-like object S3FileSystem, pytest-servers-bqqsgx/cats/cat1>, final=True, loc=4, buffer loc=4
2023-02-23 16:02:43,533 - s3fs - DEBUG - commit -- Commit <File-like object S3FileSystem, pytest-servers-bqqsgx/cats/cat1>
2023-02-23 16:02:43,533 - s3fs - DEBUG - commit -- One-shot upload of <File-like object S3FileSystem, pytest-servers-bqqsgx/cats/cat1>
2023-02-23 16:02:43,533 - s3fs - DEBUG - _call_s3 -- CALL: put_object - ({},) - {'Key': 'cats/cat1', 'Bucket': 'pytest-servers-bqqsgx', 'ACL': ''}
2023-02-23 16:02:45,590 - s3fs - DEBUG - _upload_chunk -- Upload for <File-like object S3FileSystem, pytest-servers-bqqsgx/cats/cat2>, final=True, loc=4, buffer loc=4
2023-02-23 16:02:45,590 - s3fs - DEBUG - commit -- Commit <File-like object S3FileSystem, pytest-servers-bqqsgx/cats/cat2>
2023-02-23 16:02:45,590 - s3fs - DEBUG - commit -- One-shot upload of <File-like object S3FileSystem, pytest-servers-bqqsgx/cats/cat2>
2023-02-23 16:02:45,590 - s3fs - DEBUG - _call_s3 -- CALL: put_object - ({},) - {'Key': 'cats/cat2', 'Bucket': 'pytest-servers-bqqsgx', 'ACL': ''}
2023-02-23 16:02:45,602 - s3fs - DEBUG - _call_s3 -- CALL: head_object - ({},) - {'Bucket': 'pytest-servers-bqqsgx', 'Key': 'dogs'}
2023-02-23 16:02:47,640 - s3fs - DEBUG - _error_wrapper -- Client error (maybe retryable): An error occurred (404) when calling the HeadObject operation: Not Found
2023-02-23 16:02:47,640 - s3fs - DEBUG - _call_s3 -- CALL: list_objects_v2 - ({},) - {'Bucket': 'pytest-servers-bqqsgx', 'Prefix': 'dogs/', 'Delimiter': '/', 'MaxKeys': 1}
2023-02-23 16:02:47,656 - s3fs - DEBUG - _call_s3 -- CALL: list_objects_v2 - () - {'MaxKeys': 1, 'Bucket': 'pytest-servers-bqqsgx'}
2023-02-23 16:02:49,705 - s3fs - DEBUG - _upload_chunk -- Upload for <File-like object S3FileSystem, pytest-servers-bqqsgx/dogs/dog1>, final=True, loc=4, buffer loc=4
2023-02-23 16:02:49,705 - s3fs - DEBUG - commit -- Commit <File-like object S3FileSystem, pytest-servers-bqqsgx/dogs/dog1>
2023-02-23 16:02:49,705 - s3fs - DEBUG - commit -- One-shot upload of <File-like object S3FileSystem, pytest-servers-bqqsgx/dogs/dog1>
2023-02-23 16:02:49,720 - s3fs - DEBUG - _call_s3 -- CALL: put_object - ({},) - {'Key': 'dogs/dog1', 'Bucket': 'pytest-servers-bqqsgx', 'ACL': ''}
2023-02-23 16:02:51,742 - s3fs - DEBUG - _upload_chunk -- Upload for <File-like object S3FileSystem, pytest-servers-bqqsgx/dogs/dog2>, final=True, loc=3, buffer loc=3
2023-02-23 16:02:51,742 - s3fs - DEBUG - commit -- Commit <File-like object S3FileSystem, pytest-servers-bqqsgx/dogs/dog2>
2023-02-23 16:02:51,742 - s3fs - DEBUG - commit -- One-shot upload of <File-like object S3FileSystem, pytest-servers-bqqsgx/dogs/dog2>
2023-02-23 16:02:51,742 - s3fs - DEBUG - _call_s3 -- CALL: put_object - ({},) - {'Key': 'dogs/dog2', 'Bucket': 'pytest-servers-bqqsgx', 'ACL': ''}
2023-02-23 16:02:51,760 - s3fs - DEBUG - _upload_chunk -- Upload for <File-like object S3FileSystem, pytest-servers-bqqsgx/dogs/dog3>, final=True, loc=4, buffer loc=4
2023-02-23 16:02:51,760 - s3fs - DEBUG - commit -- Commit <File-like object S3FileSystem, pytest-servers-bqqsgx/dogs/dog3>
2023-02-23 16:02:51,760 - s3fs - DEBUG - commit -- One-shot upload of <File-like object S3FileSystem, pytest-servers-bqqsgx/dogs/dog3>
2023-02-23 16:02:51,760 - s3fs - DEBUG - _call_s3 -- CALL: put_object - ({},) - {'Key': 'dogs/dog3', 'Bucket': 'pytest-servers-bqqsgx', 'ACL': ''}
2023-02-23 16:02:53,823 - s3fs - DEBUG - _call_s3 -- CALL: head_object - ({},) - {'Bucket': 'pytest-servers-bqqsgx', 'Key': 'dogs/others'}
2023-02-23 16:02:53,823 - s3fs - DEBUG - _error_wrapper -- Client error (maybe retryable): An error occurred (404) when calling the HeadObject operation: Not Found
2023-02-23 16:02:53,823 - s3fs - DEBUG - _call_s3 -- CALL: list_objects_v2 - ({},) - {'Bucket': 'pytest-servers-bqqsgx', 'Prefix': 'dogs/others/', 'Delimiter': '/', 'MaxKeys': 1}
2023-02-23 16:02:55,880 - s3fs - DEBUG - _call_s3 -- CALL: list_objects_v2 - () - {'MaxKeys': 1, 'Bucket': 'pytest-servers-bqqsgx'}
2023-02-23 16:02:55,880 - s3fs - DEBUG - _upload_chunk -- Upload for <File-like object S3FileSystem, pytest-servers-bqqsgx/dogs/others/dog4>, final=True, loc=4, buffer loc=4
2023-02-23 16:02:55,896 - s3fs - DEBUG - commit -- Commit <File-like object S3FileSystem, pytest-servers-bqqsgx/dogs/others/dog4>
2023-02-23 16:02:55,896 - s3fs - DEBUG - commit -- One-shot upload of <File-like object S3FileSystem, pytest-servers-bqqsgx/dogs/others/dog4>
2023-02-23 16:02:55,896 - s3fs - DEBUG - _call_s3 -- CALL: put_object - ({},) - {'Key': 'dogs/others/dog4', 'Bucket': 'pytest-servers-bqqsgx', 'ACL': ''}

 test_foo.py ✓                                                                                                                                                                                                                                                                                       100% ██████████
================================================================================================================================================ warnings summary =================================================================================================================================================
test_foo.py::test_foo
  Z:\devel\iterative\dql\venv\win\Lib\site-packages\botocore\utils.py:15: DeprecationWarning: 'cgi' is deprecated and slated for removal in Python 3.13
    import cgi

-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html

Results (24.66s):
       1 passed
skshetry commented 1 year ago

Maybe broadly related to https://github.com/aio-libs/aiohttp/issues/4451.

Closed by #106