mar10 / wsgidav

A generic and extendable WebDAV server based on WSGI
https://wsgidav.readthedocs.io
MIT License
978 stars 150 forks source link

PUT: byte copy failed #272

Closed Ramel closed 1 year ago

Ramel commented 1 year ago

Describe the bug Some files are not uploaded to the server.

Expected behavior Seems to be timeout related with some files.

Screenshots, Log-Files, Stacktrace

Nov  2 14:04:48 ns3151156 wsgidav_service[53781]: 14:04:48.517 - INFO    : ***.***.***.*** - *** - [2022-11-02 13:04:48] "PROPFIND ***/Test" length=99, depth=0, elap=0.056sec -> 207 Multi-Status
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]: 14:05:03.037 - ERROR   : PUT: byte copy failed
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]: Traceback (most recent call last):
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/local/lib/python3.9/dist-packages/wsgidav/request_server.py", line 837, in do_PUT
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     fileobj.writelines(data_stream)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/local/lib/python3.9/dist-packages/wsgidav/request_server.py", line 740, in _stream_data
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     readbuffer = environ["wsgi.input"].read(n)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/local/lib/python3.9/dist-packages/cheroot/server.py", line 385, in read
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     data = self.rfile.read(size)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/local/lib/python3.9/dist-packages/cheroot/makefile.py", line 420, in read
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     val = super().read(*args, **kwargs)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/lib/python3.9/_pyio.py", line 1072, in read
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     return self._read_unlocked(size)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/lib/python3.9/_pyio.py", line 1112, in _read_unlocked
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     chunk = self.raw.read(wanted)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/lib/python3.9/socket.py", line 704, in readinto
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     return self._sock.recv_into(b)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/lib/python3.9/ssl.py", line 1241, in recv_into
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     return self.read(nbytes, buffer)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/lib/python3.9/ssl.py", line 1099, in read
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     return self._sslobj.read(len, buffer)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]: socket.timeout: The read operation timed out
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]: 14:05:03.039 - ERROR   : Caught HTTPRequestException(HTTP_INTERNAL_ERROR)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]: Traceback (most recent call last):
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/local/lib/python3.9/dist-packages/wsgidav/request_server.py", line 837, in do_PUT
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     fileobj.writelines(data_stream)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/local/lib/python3.9/dist-packages/wsgidav/request_server.py", line 740, in _stream_data
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     readbuffer = environ["wsgi.input"].read(n)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/local/lib/python3.9/dist-packages/cheroot/server.py", line 385, in read
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     data = self.rfile.read(size)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/local/lib/python3.9/dist-packages/cheroot/makefile.py", line 420, in read
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     val = super().read(*args, **kwargs)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/lib/python3.9/_pyio.py", line 1072, in read
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     return self._read_unlocked(size)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/lib/python3.9/_pyio.py", line 1112, in _read_unlocked
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     chunk = self.raw.read(wanted)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/lib/python3.9/socket.py", line 704, in readinto
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     return self._sock.recv_into(b)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/lib/python3.9/ssl.py", line 1241, in recv_into
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     return self.read(nbytes, buffer)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/lib/python3.9/ssl.py", line 1099, in read
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     return self._sslobj.read(len, buffer)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]: socket.timeout: The read operation timed out
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]: During handling of the above exception, another exception occurred:
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]: Traceback (most recent call last):
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/local/lib/python3.9/dist-packages/wsgidav/error_printer.py", line 50, in __call__
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     for v in app_iter:
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/local/lib/python3.9/dist-packages/wsgidav/request_resolver.py", line 224, in __call__
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     for v in app_iter:
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/local/lib/python3.9/dist-packages/wsgidav/request_server.py", line 127, in __call__
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     app_iter = provider.custom_request_handler(environ, start_response, method)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/local/lib/python3.9/dist-packages/wsgidav/dav_provider.py", line 1592, in custom_request_handler
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     return default_handler(environ, start_response)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/local/lib/python3.9/dist-packages/wsgidav/request_server.py", line 847, in do_PUT
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     util.fail(e)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/local/lib/python3.9/dist-packages/wsgidav/util.py", line 943, in fail
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     raise e
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]: wsgidav.dav_error.DAVError: 500
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]: 14:05:03.039 - ERROR   : e.src_exception:
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]: The read operation timed out
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]: 14:05:03.040 - WARNING : Input stream not completely consumed: closing connection.
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]: 14:05:03.040 - WARNING : Adding 'Connection: close' header.
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]: 14:05:03.040 - INFO    : ***.***.***.*** - *** - [2022-11-02 13:05:03] "PUT ***/BigFile.mp4" length=135419632, elap=224.020sec -> 500 Internal Server Error
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]: socket.error 'cannot read from timed out object'
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]: Traceback (most recent call last):
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/local/lib/python3.9/dist-packages/cheroot/server.py", line 1300, in communicate
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     req.respond()
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/local/lib/python3.9/dist-packages/cheroot/server.py", line 1090, in respond
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     self.server.gateway(self).respond()
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/local/lib/python3.9/dist-packages/cheroot/wsgi.py", line 145, in respond
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     self.write(chunk)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/local/lib/python3.9/dist-packages/cheroot/wsgi.py", line 229, in write
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     self.req.ensure_headers_sent()
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/local/lib/python3.9/dist-packages/cheroot/server.py", line 1137, in ensure_headers_sent
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     self.send_headers()
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/local/lib/python3.9/dist-packages/cheroot/server.py", line 1218, in send_headers
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     self.rfile.read(remaining)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/local/lib/python3.9/dist-packages/cheroot/server.py", line 385, in read
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     data = self.rfile.read(size)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/local/lib/python3.9/dist-packages/cheroot/makefile.py", line 420, in read
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     val = super().read(*args, **kwargs)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/lib/python3.9/_pyio.py", line 1072, in read
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     return self._read_unlocked(size)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/lib/python3.9/_pyio.py", line 1112, in _read_unlocked
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     chunk = self.raw.read(wanted)
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:   File "/usr/lib/python3.9/socket.py", line 701, in readinto
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]:     raise OSError("cannot read from timed out object")
Nov  2 14:05:03 ns3151156 wsgidav_service[53781]: OSError: cannot read from timed out object
Nov  2 14:07:14 ns3151156 wsgidav_service[53781]: 

Environment:

4.0.3-a1

cheroot

QNAP HBS3

Additional context Should I increase the cheroot timeout? It's actually set to defaults.

server: cheroot

#: Server specific arguments, passed to the server. For example cheroot:
#:   https://cheroot.cherrypy.dev/en/latest/pkg/cheroot.wsgi.html#cheroot.wsgi.Server
server_args:
    max: -1
    numthreads: 10
    request_queue_size: 5
    shutdown_timeout: 5
    timeout: 10
mar10 commented 1 year ago

Does it happen after ~10 seconds? For large files only? What happens if you increase timeout. Do the logs tell more if -vv is passed?

Ramel commented 1 year ago

I've increased the timeout and it seems to go throught. Thanks.