Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Attribute error during timeout cancelling transfer #209

Merged
merged 1 commit into from
Jan 17, 2024

Conversation

jsattelb
Copy link
Contributor

Change remaining instances of errors.TicketCancelTimeout to errors.TransferCancelTimeout.

Include an initial unit test that attempts to mimic two connection attempts:

  • Connection 1 initiates the transfer
  • Connection 2 issues the delete request
  • The timeout is set to 0.0001 seconds, which seemed fast enough to raise a 409 conflict

Fixes #208

@nirs
Copy link
Member

nirs commented Jan 16, 2024

@jsattelb thanks for the fix and the nice test!

Looks like the test does not work:

____________________ test_delete_active_connection[daemon] _____________________

srv = <ovirt_imageio._internal.server.Server object at 0x7f4da82476d8>
tmpdir = local('/var/tmp/imageio-tests/test_delete_active_connection_0')

    def test_delete_active_connection(srv, tmpdir):
        # Use short timeout to keep the tests fast.
        srv.config.control.remove_timeout = 0.0001
    
        filename = tmpdir.join("image")
        # Note: must be big enough so the request remain active.
        size = 1024**3 * 100
        with open(str(filename), 'wb') as image:
            image.truncate(size)
        ticket = testutil.create_ticket(
            url="file://" + str(filename), ops=["read"], size=size)
        srv.auth.add(ticket)
    
        with http.ControlClient(srv.config) as c:
            # Start a download, but read only 1 byte to make sure the operation
            # becomes active but do not complete.
            with http.RemoteClient(srv.config) as con:
                remoteimage = con.get("/images/%(uuid)s" % ticket)
                remoteimage.read(1)
                res = c.delete("/tickets/%(uuid)s" % ticket)
>               assert res.status == 409
E               assert 204 == 409
E                +  where 204 = <http.client.HTTPResponse object at 0x7f4da816bf60>.status

test/handlers/tickets_test.py:422: AssertionError
----------------------------- Captured stdout call -----------------------------
(200, 'OK', 11)
[('server', 'imageio/2.5.1'),
 ('date', 'Tue, 16 Jan 2024 19:05:49 GMT'),
 ('content-length', '107374182400'),
 ('content-type', 'application/octet-stream'),
 ('content-disposition', 'attachment')]
(204, 'No Content', 11)
[('server', 'imageio/2.5.1'),
 ('date', 'Tue, 16 Jan 2024 19:05:49 GMT'),
 ('content-length', '0')]
------------------------------ Captured log call -------------------------------
19:05:49,061 INFO    (Thread-2911) [http] OPEN connection=1[177](https://github.com/oVirt/ovirt-imageio/actions/runs/7534912276/job/20543766695?pr=209#step:4:178) client=::1
19:05:49,061 DEBUG   (Thread-2911) [auth] AUTH op=read transfer=4769c3fa-cea6-40fc-b3d3-c51c3b1ab616
19:05:49,062 DEBUG   (Thread-2911) [backends.file] Open path='/var/tmp/imageio-tests/test_delete_active_connection_0/image' mode='rb' sparse=False max_connections=8
19:05:49,062 DEBUG   (Thread-2911) [backends.file] Trying block size 1
19:05:49,062 DEBUG   (Thread-2911) [backends.file] Cannot detect block size - using 4096
19:05:49,062 DEBUG   (Thread-2911) [auth] Adding connection 1177 context to transfer 4769c3fa-cea6-40fc-b3d3-c51c3b1ab616
19:05:49,062 DEBUG   (Thread-2911) [http] Setting connection timeout to 120 seconds
19:05:49,062 DEBUG   (Thread-2911) [images] [::1] READ size=107374182400 offset=0 close=False transfer=4769c3fa-cea6-40fc-b3d3-c51c3b1ab616
19:05:49,063 INFO    (Thread-2912) [http] OPEN connection=1[178](https://github.com/oVirt/ovirt-imageio/actions/runs/7534912276/job/20543766695?pr=209#step:4:179) client=local
19:05:49,064 INFO    (Thread-2912) [tickets] [local] REMOVE transfer=4769c3fa-cea6-40fc-b3d3-c51c3b1ab616
19:05:49,064 DEBUG   (Thread-2912) [auth] Cancelling transfer 4769c3fa-cea6-40fc-b3d3-c51c3b1ab616
19:05:49,064 DEBUG   (Thread-2912) [auth] Canceling transfer 4769c3fa-cea6-40fc-b3d3-c51c3b1ab616 ongoing operations
19:05:49,064 DEBUG   (Thread-2912) [ops] Cancelling operation <Read size=107374[182](https://github.com/oVirt/ovirt-imageio/actions/runs/7534912276/job/20543766695?pr=209#step:4:183)400 offset=0 done=262144 at 0x139971511474160>
19:05:49,064 INFO    (Thread-2912) [auth] Waiting until transfer 4769c3fa-cea6-40fc-b3d3-c51c3b1ab616 ongoing operations finish
19:05:49,064 DEBUG   (Thread-2911) [auth] Operation <Read size=107374182400 offset=0 done=393216 at 0x139971511474160> was canceled
19:05:49,064 DEBUG   (Thread-2911) [auth] Removed last ongoring operation for transfer 4769c3fa-cea6-40fc-b3d3-c51c3b1ab616
19:05:49,065 ERROR   (Thread-2911) [http] Request aborted after starting response
Traceback (most recent call last):
  File "/__w/ovirt-imageio/ovirt-imageio/ovirt_imageio/_internal/http.py", line 796, in __call__
    self.dispatch(req, resp)
  File "/__w/ovirt-imageio/ovirt-imageio/ovirt_imageio/_internal/http.py", line 841, in dispatch
    return method(req, resp, *match.groups())
  File "/__w/ovirt-imageio/ovirt-imageio/ovirt_imageio/_internal/cors.py", line 80, in wrapper
    return func(self, req, resp, *args)
  File "/__w/ovirt-imageio/ovirt-imageio/ovirt_imageio/_internal/handlers/images.py", line 146, in get
    raise http.Error(http.FORBIDDEN, str(e)) from None
ovirt_imageio._internal.http.Error: You are not allowed to access this resource: Transfer 4769c3fa-cea6-40fc-b3d3-c51c3b1ab616 was canceled
19:05:49,065 DEBUG   (Thread-2912) [backends.file] Close path='/var/tmp/imageio-tests/test_delete_active_connection_0/image' dirty=False
19:05:49,065 INFO    (Thread-2912) [auth] Transfer 4769c3fa-cea6-40fc-b3d3-c51c3b1ab616 was canceled
19:05:49,065 DEBUG   (Thread-2911) [auth] Removing connection 1177 context from transfer 4769c3fa-cea6-40fc-b3d3-c51c3b1ab616
19:05:49,065 INFO    (Thread-2911) [http] CLOSE connection=1177 client=::1 [connection 1 ops, 0.003695 s] [dispatch 1 ops, 0.003480 s] [read 0 ops, 0.002283 s] [read.read 3 ops, 0.000211 s, 384.00 KiB, 1.73 GiB/s] [read.write 3 ops, 0.001949 s, 384.00 KiB, 192.38 MiB/s]
19:05:49,067 DEBUG   (Thread-2912) [http] Empty request line, client disconnected
19:05:49,067 INFO    (Thread-2912) [http] CLOSE connection=1178 client=local [connection 1 ops, 0.003358 s] [dispatch 1 ops, 0.00[183](https://github.com/oVirt/ovirt-imageio/actions/runs/7534912276/job/20543766695?pr=209#step:4:184)4 s]

In this case the fix is trivial, and testing it is 10 times more complicated. I think having a test is nice to have, but lets first the issue first, and move the test to another PR.

Copy link
Member

@nirs nirs left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fix is good, test need more work.

test/handlers/tickets_test.py Outdated Show resolved Hide resolved
ovirt_imageio/_internal/handlers/tickets.py Show resolved Hide resolved
test/handlers/tickets_test.py Show resolved Hide resolved
@nirs
Copy link
Member

nirs commented Jan 16, 2024

Test works now :-)

The only obstacle is missing Signged-off-by header in the commit message:
https://github.com/oVirt/ovirt-imageio/pull/209/checks?check_run_id=20548982117

@jsattelb
Copy link
Contributor Author

My fault!

Copy link
Member

@nirs nirs left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I forgot to mention that we like clean history - every commit does one logical change. This change can be one commit or 2 commits (fix, test).

If you don't know how to rebase we can handle this.

Thanks!

- Change remaining instances of errors.TicketCancelTimeout to errors.TransferCancelTimeout
- Include an initial unit test that attempts to mimic two connection attempts:
  - Connection 1 initiates the transfer
  - Connection 2 issues the delete request
- Fixed unit test to incorporate suggestions:
  - Use testutil.create_tempfile to create temporary file
  - Use a smaller file, 8 MiB (hopefully) is enough to simulate the issue
  - Use monkeypatch.setattr() to modify global values for test_delete_conflict test
  - Use time.sleep() instead of reading one byte

Signed-off-by: jsattelb <jsattelb@ldeo.columbia.edu>
@jsattelb
Copy link
Contributor Author

I forgot to mention that we like clean history - every commit does one logical change. This change can be one commit or 2 commits (fix, test).

If you don't know how to rebase we can handle this.

Thanks!

Done.

Copy link
Member

@aesteve-rh aesteve-rh left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks good to me. Thank you!

@aesteve-rh aesteve-rh merged commit 3fddc24 into oVirt:master Jan 17, 2024
13 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Attribute error during timeout cancelling transfer
3 participants