Bug 1523203
| Summary: | ImageIO- upload pause cause nasty log ERROR in both Engine image-proxy.log & in VDSM host daemon.log | ||||||||
|---|---|---|---|---|---|---|---|---|---|
| Product: | [oVirt] ovirt-imageio | Reporter: | Avihai <aefrat> | ||||||
| Component: | Daemon | Assignee: | Idan Shaby <ishaby> | ||||||
| Status: | CLOSED CURRENTRELEASE | QA Contact: | Avihai <aefrat> | ||||||
| Severity: | medium | Docs Contact: | |||||||
| Priority: | high | ||||||||
| Version: | --- | CC: | aefrat, amureini, bugs, derez, ebenahar, ishaby, lveyde, nsoffer, tnisan, ylavi | ||||||
| Target Milestone: | ovirt-4.2.2 | Flags: | rule-engine:
ovirt-4.2+
ylavi: exception+ |
||||||
| Target Release: | --- | ||||||||
| Hardware: | Unspecified | ||||||||
| OS: | Unspecified | ||||||||
| Whiteboard: | |||||||||
| Fixed In Version: | 4.2.2 RC5, imageio v1.2.2 | Doc Type: | If docs needed, set a value | ||||||
| Doc Text: | Story Points: | --- | |||||||
| Clone Of: | Environment: | ||||||||
| Last Closed: | 2018-04-05 09:39:20 UTC | Type: | Bug | ||||||
| Regression: | --- | Mount Type: | --- | ||||||
| Documentation: | --- | CRM: | |||||||
| Verified Versions: | Category: | --- | |||||||
| oVirt Team: | Storage | RHEL 7.3 requirements from Atomic Host: | |||||||
| Cloudforms Team: | --- | Target Upstream Version: | |||||||
| Embargoed: | |||||||||
| Attachments: |
|
||||||||
Avihai, I couldn't reproduce the error that you got in the proxy's log. Can you please see if you still get that error? I checked at 4.2.1.3-0.1.el7 & issue looks fixed (exception is not seen) (In reply to Avihai from comment #2) > I checked at 4.2.1.3-0.1.el7 & issue looks fixed (exception is not seen) Sorry, disregard the last remark as it was for another bug (1534444). This issue does reproduce on 4.2.1.3-0.1.el7 with cancel upload scenario . See logs attach. Created attachment 1388906 [details]
engine , image_proxy ,vdsm,deamon logs
See the last line in image_proxy.log :
(Thread-793) ERROR 2018-01-31 12:25:04,779 web:112:web:(log_error) ERROR [10.35.206.23] PUT /images/cfb9b88f-574b-44c7-be01-75d5a5fa4dac: [500] The client disconnected while sending the POST/PUT body (94699520 more bytes were expected) (29.17s)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/ovirt_imageio_common/web.py", line 64, in __call__
resp = self.dispatch(request)
File "/usr/lib/python2.7/site-packages/ovirt_imageio_common/web.py", line 91, in dispatch
return method(*match.groups())
File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/http_helper.py", line 104, in wrapper
return func(self, *args)
File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/http_helper.py", line 60, in wrapper
ret = func(self, *args)
File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/images.py", line 97, in put
self.request.method, imaged_url, headers, body, stream)
File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/images.py", line 134, in make_imaged_request
timeout=timeout, stream=stream)
File "/usr/lib/python2.7/site-packages/requests/sessions.py", line 576, in send
r = adapter.send(request, **kwargs)
File "/usr/lib/python2.7/site-packages/requests/adapters.py", line 370, in send
timeout=timeout
File "/usr/lib/python2.7/site-packages/urllib3/connectionpool.py", line 544, in urlopen
body=body, headers=headers)
File "/usr/lib/python2.7/site-packages/urllib3/connectionpool.py", line 349, in _make_request
conn.request(method, url, **httplib_request_kw)
File "/usr/lib64/python2.7/httplib.py", line 1017, in request
self._send_request(method, url, body, headers)
File "/usr/lib64/python2.7/httplib.py", line 1051, in _send_request
self.endheaders(body)
File "/usr/lib64/python2.7/httplib.py", line 1013, in endheaders
self._send_output(message_body)
File "/usr/lib64/python2.7/httplib.py", line 868, in _send_output
self.send(message_body)
File "/usr/lib64/python2.7/httplib.py", line 838, in send
datablock = data.read(blocksize)
File "/usr/lib/python2.7/site-packages/ovirt_imageio_common/web.py", line 194, in read
chunk = self.input_stream.read(to_read)
File "/usr/lib/python2.7/site-packages/webob/request.py", line 1528, in readinto
+ "(%d more bytes were expected)" % self.remaining
DisconnectionError: The client disconnected while sending the POST/PUT body (94699520 more bytes were expected)
OK, was it an upload flow via webadmin + cancel in the middle? (In reply to Idan Shaby from comment #5) > OK, was it an upload flow via webadmin + cancel in the middle? Yes, start upload disk, wait until you see upload progress bar & than cancel. I still cannot reproduce it on latest engine-vdsm-daemon-proxy (master). Are you using the latest versions of all the above? INFO: Bug status wasn't changed from MODIFIED to ON_QA due to the following reason: [No relevant external trackers attached] For more info please contact: infra Indeed, thanks for noticing. Hi Idan, According to ovirt-Image-io webgit this bug will only be fixed in the next image-io build (1.2.2 I presume?) . On current latest downstream build (4.2.2-4) the ovirt-Image-io proxy/deamon/common is 1.2.1 -> see link: http://bob.eng.lab.tlv.redhat.com/builds/4.2/rhv-4.2.2-4/el7Server/noarch/ Please move bug to back to 'ON QA' until this fix is merged inserted to latest downstream. The fix is in imageio, not the engine. Changing product/component automatically. Idan, didn't we disable the cancel button during upload? This bug seems to happen only when using this option. No, we disabled it during image download to fix Bug 1540539. No build has been issued for 4.2.2 RC4, please build ASAP for having it included in 4.2.2 GA Daniel, will you make it to build image-io? (In reply to Idan Shaby from comment #16) > Daniel, will you make it to build image-io? Yes, imageio 1.2.2 should be released soon. Verified on : ovirt-engine 4.2.2.6-0.1.el7 ovirt-imageio-daemon-1.2.2-0.el7ev.noarch This bugzilla is included in oVirt 4.2.2 release, published on March 28th 2018. Since the problem described in this bug report should be resolved in oVirt 4.2.2 release, it has been closed with a resolution of CURRENT RELEASE. If the solution does not work for you, please open a new bug report. |
Created attachment 1364288 [details] engine , vdsm ,image_proxy,image_demon logs Description of problem: upload pause causes nasty log ERROR in both VDSM host deamon.log & engine proxy log. If this is indeed not an error but expected please change it to an informative INFO message. Version-Release number of selected component (if applicable): How reproducible: 100% Steps to Reproduce: 1.Start disk upload via UI/SDK 2.Pause disk upload Actual results: Nasty errors appear in Engine image-proxy.log & in VDSM host daemon.log : Engine image-proxy.log: (Thread-8 ) ERROR 2017-12-07 11:24:15,311 web:89:web:(log_response) 10.35.4.169 - PUT 500 253 (3.44s) Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/ovirt_imageio_common/web.py", line 48, in __call__ resp = self.dispatch(request) File "/usr/lib/python2.7/site-packages/ovirt_imageio_common/web.py", line 73, in dispatch return method(*match.groups()) File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/http_helper.py", line 88, in wrapper ret = func(self, *args) File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/http_helper.py", line 59, in wrapper ret = func(self, *args) File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/images.py", line 79, in put return self.send_data(self.request) File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/images.py", line 116, in send_data request.method, imaged_url, headers, body, stream) File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/images.py", line 176, in make_imaged_request timeout=timeout, stream=stream) File "/usr/lib/python2.7/site-packages/requests/sessions.py", line 576, in send r = adapter.send(request, **kwargs) File "/usr/lib/python2.7/site-packages/requests/adapters.py", line 370, in send timeout=timeout File "/usr/lib/python2.7/site-packages/urllib3/connectionpool.py", line 544, in urlopen body=body, headers=headers) File "/usr/lib/python2.7/site-packages/urllib3/connectionpool.py", line 349, in _make_request conn.request(method, url, **httplib_request_kw) File "/usr/lib64/python2.7/httplib.py", line 1017, in request self._send_request(method, url, body, headers) File "/usr/lib64/python2.7/httplib.py", line 1051, in _send_request self.endheaders(body) File "/usr/lib64/python2.7/httplib.py", line 1013, in endheaders self._send_output(message_body) File "/usr/lib64/python2.7/httplib.py", line 868, in _send_output self.send(message_body) File "/usr/lib64/python2.7/httplib.py", line 838, in send datablock = data.read(blocksize) File "/usr/lib/python2.7/site-packages/ovirt_imageio_common/web.py", line 171, in read chunk = self.input_stream.read(to_read) File "/usr/lib/python2.7/site-packages/webob/request.py", line 1528, in readinto + "(%d more bytes were expected)" % self.remaining DisconnectionError: The client disconnected while sending the POST/PUT body (64487424 more bytes were expected) VDSM host proxy log output: 2017-12-07 11:24:11,886 INFO (Thread-7) [images] Writing 104857600 bytes at offset 629145600 to /rhev/data-center/mnt/blockSD/5820c57b-a8fb-4169-9b08-bcf28753c4f6/images/a000ecda-7c44-4325-99c7-92f711c92a27/4 ce89e2b-c750-4d3d-8c7f-ff58e5569d48 for ticket bff55936-d7d9-4bb1-aec2-5176b1250a75 2017-12-07 11:24:15,355 ERROR (Thread-7) [web] 10.35.161.118 - PUT /bff55936-d7d9-4bb1-aec2-5176b1250a75 500 213 (3.46s) Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/ovirt_imageio_common/web.py", line 48, in __call__ resp = self.dispatch(request) File "/usr/lib/python2.7/site-packages/ovirt_imageio_common/web.py", line 73, in dispatch return method(*match.groups()) File "/usr/lib/python2.7/site-packages/ovirt_imageio_daemon/server.py", line 162, in put op.run() File "/usr/lib/python2.7/site-packages/ovirt_imageio_common/directio.py", line 72, in run self._run() File "/usr/lib/python2.7/site-packages/ovirt_imageio_common/directio.py", line 160, in _run self._receive_chunk(dst, buf, count) File "/usr/lib/python2.7/site-packages/ovirt_imageio_common/directio.py", line 196, in _receive_chunk raise errors.PartialContent(self.size, self.done) PartialContent: Requested 104857600 bytes, available 40370176 bytes Expected results: Additional info: