Created attachment 1180763 [details] engine.log, vdsm.log, image-proxy.log Description of problem: When trying to upload an image, after a few seconds upload pauses by the system. Version-Release number of selected component (if applicable): rhevm-4.0.2-0.2.rc1.el7ev.noarch ovirt-imageio-common-0.3.0-0.el7ev.noarch ovirt-imageio-proxy-0.3.0-0.el7ev.noarch vdsm-4.18.6-1.el7ev.x86_64 ovirt-imageio-daemon-0.3.0-0.el7ev.noarch How reproducible: 100% Steps to Reproduce: 1. Install engine (http://bob.eng.lab.tlv.redhat.com/builds/4.0/4.0.1-2/el$releasever) 2. Configure certificate. 3. Restart browser 4. Try to upload an image using the UI. Actual results: When trying to upload an image, it fails: engine.log gets filled with this warning: 2016-07-17 15:54:57,008 WARN [org.ovirt.engine.core.bll.storage.disk.image.UploadDiskImageCommand] (DefaultQuartzScheduler3) [68166d78] Failed to stop image transfer session. Ticket does not exist for image 'f4a81fe1-0abc-4ba4-945f-12ec96a1bf68' Expected results: For the file to be uploaded successfully. Additional info: * I tried removing both hosts and reinstall them (vdsm, ovirt-imageio-common and ovirt-image-daemon). * Also tried uploading with only one active host (the other one in maintenance) * Tried both block and file storage types. * Tried both Chrome and Firefox, also removing the certificate and reconfiguring the browser to work with it.
Daniel, can you please take a quick look here to see what we're up against?
According to the image-proxy log [1], there was an SSL error during connection. @Natalie - did you change/modified the certificate or something similar? @Nir - are you familiar with these kind of error in the proxy? [1] (Thread-10 ) ERROR 2016-07-17 14:07:37,716 image_handler:186:root:(make_imaged_request) Failed communicating with vdsm-imaged: An SSL error occurred. Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/image_handler.py", line 177, 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 431, in send raise SSLError(e, request=request) SSLError: [SSL: CERTIFICATE_VERIFY_FAILED] certificate verify failed (_ssl.c:765)
Natalie, can you try to restart the ovirt-imageio-daemon service? Can you upload after the restart? Also, can you attach the output: journalctl -x -u ovirt-imageio-daemon
Created attachment 1180859 [details] imageio daemon log Output of: journalctl -x -u ovirt-imageio-daemon
In the log we see that requests are failing with internal server error after the service was started - this does not seems like ssl issue. -- Unit ovirt-imageio-daemon.service has begun starting up. Jul 17 15:09:32 aqua-vds4.qa.lab.tlv.redhat.com systemd[1]: Started oVirt ImageIO Daemon. -- Subject: Unit ovirt-imageio-daemon.service has finished start-up -- Defined-By: systemd -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel -- -- Unit ovirt-imageio-daemon.service has finished starting up. -- -- The start-up result is done. Jul 17 15:12:07 aqua-vds4.qa.lab.tlv.redhat.com ovirt-imageio-daemon[1489]: / - - [17/Jul/2016 15:12:07] "PUT /tickets/13036476-5198-4bba-b75c-d50867b44726 HTTP/1.1" 200 0 Jul 17 15:12:20 aqua-vds4.qa.lab.tlv.redhat.com ovirt-imageio-daemon[1489]: 10.35.161.132 - - [17/Jul/2016 15:12:20] "PUT /images/13036476-5198-4bba-b75c-d50867b44726 HTTP/1.1" 500 210 Jul 17 15:12:33 aqua-vds4.qa.lab.tlv.redhat.com ovirt-imageio-daemon[1489]: 10.35.161.132 - - [17/Jul/2016 15:12:33] "PUT /images/13036476-5198-4bba-b75c-d50867b44726 HTTP/1.1" 500 210 Jul 17 15:12:46 aqua-vds4.qa.lab.tlv.redhat.com ovirt-imageio-daemon[1489]: 10.35.161.132 - - [17/Jul/2016 15:12:46] "PUT /images/13036476-5198-4bba-b75c-d50867b44726 HTTP/1.1" 500 210 Jul 17 15:12:59 aqua-vds4.qa.lab.tlv.redhat.com ovirt-imageio-daemon[1489]: 10.35.161.132 - - [17/Jul/2016 15:12:59] "PUT /images/13036476-5198-4bba-b75c-d50867b44726 HTTP/1.1" 500 210 Jul 17 15:13:02 aqua-vds4.qa.lab.tlv.redhat.com ovirt-imageio-daemon[1489]: / - - [17/Jul/2016 15:13:02] "DELETE /tickets/13036476-5198-4bba-b75c-d50867b44726 HTTP/1.1" 204 0 We don't have enough info in the log about this error. We will have to test with this patch, improving logging: https://gerrit.ovirt.org/59076 In the proxy log, we don't see any useful info about the failing requests: (Thread-37 ) INFO 2016-07-17 15:12:10,463 session:259:root:(_decode_proxy_ticket) Proxy ticket valid: {u'iat': 1468757525, u'imaged-uri': u'https://aqua-vds4.scl.lab.tlv.red hat.com:54322', u'nbf': 1468757525, u'exp': 1468761125, u'transfer-ticket': u'13036476-5198-4bba-b75c-d50867b44726'} (Thread-37 ) INFO 2016-07-17 15:12:10,464 session:191:root:(_create_update_session) Established session: expiration: '1468761125', imaged-host-uri: 'https://aqua-vds4.scl.la b.tlv.redhat.com:54322', proxy-ticket: 'eyJzYWx0IjoieVpVZCtsdXY5ejg9IiwiZGF0YSI6IntcbiAgXCJuYmZcIiA6...MjAxNjA3MTcxMjEyMDUiLCJ2YWxpZFRvIjoiMjAxNjA3MTcxMzEyMDUifQ==', session -id: 'd1341a08-735a-4958-aedb-8467aaee1190', transfer-ticket: '13036476-5198-4bba-b75c-d50867b44726' (Thread-37 ) INFO 2016-07-17 15:12:10,468 connectionpool:735:requests.packages.urllib3.connectionpool:(_new_conn) Starting new HTTPS connection (1): aqua-vds4.scl.lab.tlv.re dhat.com (Thread-40 ) INFO 2016-07-17 15:12:23,022 session:259:root:(_decode_proxy_ticket) Proxy ticket valid: {u'iat': 1468757525, u'imaged-uri': u'https://aqua-vds4.scl.lab.tlv.red hat.com:54322', u'nbf': 1468757525, u'exp': 1468761125, u'transfer-ticket': u'13036476-5198-4bba-b75c-d50867b44726'} (Thread-40 ) INFO 2016-07-17 15:12:23,023 session:191:root:(_create_update_session) Established session: expiration: '1468761125', imaged-host-uri: 'https://aqua-vds4.scl.la b.tlv.redhat.com:54322', proxy-ticket: 'eyJzYWx0IjoieVpVZCtsdXY5ejg9IiwiZGF0YSI6IntcbiAgXCJuYmZcIiA6...MjAxNjA3MTcxMjEyMDUiLCJ2YWxpZFRvIjoiMjAxNjA3MTcxMzEyMDUifQ==', session -id: 'b350f53e-55e4-4850-9bbc-eac147b57115', transfer-ticket: '13036476-5198-4bba-b75c-d50867b44726' (Thread-40 ) INFO 2016-07-17 15:12:23,025 connectionpool:735:requests.packages.urllib3.connectionpool:(_new_conn) Starting new HTTPS connection (1): aqua-vds4.scl.lab.tlv.re dhat.com (Thread-42 ) INFO 2016-07-17 15:12:36,036 session:259:root:(_decode_proxy_ticket) Proxy ticket valid: {u'iat': 1468757525, u'imaged-uri': u'https://aqua-vds4.scl.lab.tlv.red hat.com:54322', u'nbf': 1468757525, u'exp': 1468761125, u'transfer-ticket': u'13036476-5198-4bba-b75c-d50867b44726'} (Thread-42 ) INFO 2016-07-17 15:12:36,036 session:191:root:(_create_update_session) Established session: expiration: '1468761125', imaged-host-uri: 'https://aqua-vds4.scl.la b.tlv.redhat.com:54322', proxy-ticket: 'eyJzYWx0IjoieVpVZCtsdXY5ejg9IiwiZGF0YSI6IntcbiAgXCJuYmZcIiA6...MjAxNjA3MTcxMjEyMDUiLCJ2YWxpZFRvIjoiMjAxNjA3MTcxMzEyMDUifQ==', session -id: 'dfa7a9c6-2cf6-4ba3-a5d8-8611bd82d5d6', transfer-ticket: '13036476-5198-4bba-b75c-d50867b44726' (Thread-42 ) INFO 2016-07-17 15:12:36,039 connectionpool:735:requests.packages.urllib3.connectionpool:(_new_conn) Starting new HTTPS connection (1): aqua-vds4.scl.lab.tlv.re dhat.com (Thread-44 ) INFO 2016-07-17 15:12:49,082 session:259:root:(_decode_proxy_ticket) Proxy ticket valid: {u'iat': 1468757525, u'imaged-uri': u'https://aqua-vds4.scl.lab.tlv.red hat.com:54322', u'nbf': 1468757525, u'exp': 1468761125, u'transfer-ticket': u'13036476-5198-4bba-b75c-d50867b44726'} (Thread-44 ) INFO 2016-07-17 15:12:49,083 session:191:root:(_create_update_session) Established session: expiration: '1468761125', imaged-host-uri: 'https://aqua-vds4.scl.la b.tlv.redhat.com:54322', proxy-ticket: 'eyJzYWx0IjoieVpVZCtsdXY5ejg9IiwiZGF0YSI6IntcbiAgXCJuYmZcIiA6...MjAxNjA3MTcxMjEyMDUiLCJ2YWxpZFRvIjoiMjAxNjA3MTcxMzEyMDUifQ==', session -id: '73288b62-1c01-41c2-a985-d38bd9bf0be6', transfer-ticket: '13036476-5198-4bba-b75c-d50867b44726' (Thread-44 ) INFO 2016-07-17 15:12:49,086 connectionpool:735:requests.packages.urllib3.connectionpool:(_new_conn) Starting new HTTPS connection (1): aqua-vds4.scl.lab.tlv.redhat.com So we will need to improve proxy logging as well.
Created attachment 1180984 [details] engine.log, vdsm.log, image-proxy.log and output of journalctl command Well, since of this morning, when trying to upload an image - UI does show a progress bar, with progress status ("some mb's out of total mb's") eventually, when uploading finishes (or at least that's what it shows), status turns to "finalizing failure".. then switches status to illegal. engine.log is filled with these messages during the upload: 2016-07-18 11:50:13,680 INFO [org.ovirt.engine.core.bll.storage.disk.image.UploadImageStatusCommand] (default task-10) [2b1f44f4] Running command: UploadImageStatusCommand internal: false. Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type: SystemAction group CREATE_DISK with role type USER 2016-07-18 11:50:16,055 WARN [org.ovirt.engine.core.bll.storage.disk.image.UploadDiskImageCommand] (DefaultQuartzScheduler5) [46702861] Failed to stop image transfer session. Ticket does not exist for image '9b41dc6d-62ad-4a72-9c7b-7f666f76633d' 2016-07-18 11:50:16,129 INFO [org.ovirt.engine.core.bll.aaa.SessionDataContainer] (DefaultQuartzScheduler10) [2dffaf99] Not removing session 'F0S2X8hvMTADDjHh1XZEXUZhrg4IvySW+a/g2XHQXjH2bt4TxZfubeLjIVAmqr5vCO86RaNWZkNUY/Xr6ZdpaA==', session has running commands for user 'admin@internal-authz'. Same happens after restarting the ovirt-imageio-daemon. Added logs before restating the daemon and after. Added output for journalctl -x -u ovirt-imageio-daemon
Created attachment 1181047 [details] engine.log, vdsm.log, image-proxy.log, output of journalctl command (and the patch itself) I've used the patch Nir sent me. Attached output of journalctl -x -u ovirt-imageio-daemon and logs.
(In reply to Natalie Gavrielov from comment #6) > Created attachment 1180984 [details] > engine.log, vdsm.log, image-proxy.log and output of journalctl command > > Well, since of this morning, when trying to upload an image - UI does show a > progress bar, with progress status ("some mb's out of total mb's") > eventually, when uploading finishes (or at least that's what it shows), > status turns to "finalizing failure".. then switches status to illegal. > > engine.log is filled with these messages during the upload: > 2016-07-18 11:50:13,680 INFO > [org.ovirt.engine.core.bll.storage.disk.image.UploadImageStatusCommand] > (default task-10) [2b1f44f4] Running command: UploadImageStatusCommand > internal: false. Entities affected : ID: > aaa00000-0000-0000-0000-123456789aaa Type: SystemAction group CREATE_DISK > with role type USER > > 2016-07-18 11:50:16,055 WARN > [org.ovirt.engine.core.bll.storage.disk.image.UploadDiskImageCommand] > (DefaultQuartzScheduler5) [46702861] Failed to stop image transfer session. > Ticket does not exist for image '9b41dc6d-62ad-4a72-9c7b-7f666f76633d' > > 2016-07-18 11:50:16,129 INFO > [org.ovirt.engine.core.bll.aaa.SessionDataContainer] > (DefaultQuartzScheduler10) [2dffaf99] Not removing session > 'F0S2X8hvMTADDjHh1XZEXUZhrg4IvySW+a/ > g2XHQXjH2bt4TxZfubeLjIVAmqr5vCO86RaNWZkNUY/Xr6ZdpaA==', session has running > commands for user 'admin@internal-authz'. > > Same happens after restarting the ovirt-imageio-daemon. > > Added logs before restating the daemon and after. > Added output for journalctl -x -u ovirt-imageio-daemon Thanks Natalie, the new logs show that the daemon is successfully uploading images. The patch you tested should only change the error returned if an invalid request was submitted, but now we see only valid requests. Maybe there was some other issue in the daemon fix in upstream version before, we need to compare the latest el7 release to upstream version. What you describe now smells like engine or ui issue. Can you test downgrade again to the latest el7 package, and test if you can reproduce the error when daemon requests fail with code 500, as seen in comment 5?
Adding needinfo for Natalie, somehow removed by bugzilla gods.
> > Thanks Natalie, the new logs show that the daemon is successfully uploading > images. The patch you tested should only change the error returned if an > invalid > request was submitted, but now we see only valid requests. > > Maybe there was some other issue in the daemon fix in upstream version > before, > we need to compare the latest el7 release to upstream version. > > What you describe now smells like engine or ui issue. > > Can you test downgrade again to the latest el7 package, and test if you can > reproduce the error when daemon requests fail with code 500, as seen in > comment 5? Can you please be more specific (specify exactly what versions)? I am not sure I understand.
(In reply to Aharon Canan from comment #10) > > Can you test downgrade again to the latest el7 package, and test if you can > > reproduce the error when daemon requests fail with code 500, as seen in > > comment 5? > > Can you please be more specific (specify exactly what versions)? > I am not sure I understand. The latest released used when opening this bug - looking in comment 0: ovirt-imageio-common-0.3.0-0.el7ev.noarch
(In reply to Nir Soffer from comment #11) > (In reply to Aharon Canan from comment #10) > > > Can you test downgrade again to the latest el7 package, and test if you can > > > reproduce the error when daemon requests fail with code 500, as seen in > > > comment 5? > > > > Can you please be more specific (specify exactly what versions)? > > I am not sure I understand. > > The latest released used when opening this bug - looking in comment 0: > ovirt-imageio-common-0.3.0-0.el7ev.noarch Same pkgs from the description but latest rhel7? is that what you are asking? If so, Do you think that latest pkgs from rhel will solve this issue ?
(In reply to Aharon Canan from comment #12) > > > Can you please be more specific (specify exactly what versions)? > > > I am not sure I understand. > > > > The latest released used when opening this bug - looking in comment 0: > > ovirt-imageio-common-0.3.0-0.el7ev.noarch > > Same pkgs from the description but latest rhel7? is that what you are asking? > > If so, Do you think that latest pkgs from rhel will solve this issue ? No, but it will tell us if this issue is related to the daemon, so we can look up the next component.
So this bug is not 100% reproducible, but not reproducible at all. We don't know why the upload failed on the daemon side - we got error code 500 and there is no other info in the logs or in the proxy, so we cannot do anything on the daemon and proxy side except improving the logs. We have this patch for improving the daemon logs: https://gerrit.ovirt.org/59076 We need to improve the proxy log so we see detailed error messages from the daemon. We still to check the engine logs, maybe there is some clue there. If we don't have any info, i think we should close this and reopen when we have more data.
(In reply to Nir Soffer from comment #14) > So this bug is not 100% reproducible, but not reproducible at all. > > We don't know why the upload failed on the daemon side - we got error code > 500 and there is no other info in the logs or in the proxy, so we cannot do > anything on the daemon and proxy side except improving the logs. > > We have this patch for improving the daemon logs: > https://gerrit.ovirt.org/59076 > > We need to improve the proxy log so we see detailed error messages from the > daemon. > > We still to check the engine logs, maybe there is some clue there. > > If we don't have any info, i think we should close this and reopen when we > have > more data. Closing. Please re-open if reproduced and attach the daemon's improved logs .
rhv-release-4.1.0-4-001.noarch vdsm-4.19.1-1.el7ev.x86_64 ovirt-engine-4.1.0-0.3.beta2.el7.noarch On a host system I have similar bug: # systemctl start ovirt-imageio-daemon Job for ovirt-imageio-daemon.service failed because the control process exited with error code. See "systemctl status ovirt-imageio-daemon.service" and "journalctl -xe" for details. # journalctl -x -u ovirt-imageio-daemon --no-pager shows: Jan 17 17:26:38 spiceqe.brq.redhat.com systemd[1]: Unit ovirt-imageio-daemon.service entered failed state. Jan 17 17:26:38 spiceqe.brq.redhat.com systemd[1]: ovirt-imageio-daemon.service failed. Jan 17 17:26:38 spiceqe.brq.redhat.com systemd[1]: ovirt-imageio-daemon.service holdoff time over, scheduling restart. Jan 17 17:26:38 spiceqe.brq.redhat.com systemd[1]: Starting oVirt ImageIO Daemon... -- Subject: Unit ovirt-imageio-daemon.service has begun start-up -- Defined-By: systemd -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel -- -- Unit ovirt-imageio-daemon.service has begun starting up. Jan 17 17:26:39 spiceqe.brq.redhat.com ovirt-imageio-daemon[18192]: Traceback (most recent call last): Jan 17 17:26:39 spiceqe.brq.redhat.com ovirt-imageio-daemon[18192]: File "/usr/bin/ovirt-imageio-daemon", line 14, in <module> Jan 17 17:26:39 spiceqe.brq.redhat.com ovirt-imageio-daemon[18192]: server.main(sys.argv) Jan 17 17:26:39 spiceqe.brq.redhat.com ovirt-imageio-daemon[18192]: File "/usr/lib/python2.7/site-packages/ovirt_imageio_daemon/server.py", line 50, in main Jan 17 17:26:39 spiceqe.brq.redhat.com ovirt-imageio-daemon[18192]: configure_logger() Jan 17 17:26:39 spiceqe.brq.redhat.com ovirt-imageio-daemon[18192]: File "/usr/lib/python2.7/site-packages/ovirt_imageio_daemon/server.py", line 68, in configure_logger Jan 17 17:26:39 spiceqe.brq.redhat.com ovirt-imageio-daemon[18192]: logging.config.fileConfig(conf, disable_existing_loggers=False) Jan 17 17:26:39 spiceqe.brq.redhat.com ovirt-imageio-daemon[18192]: File "/usr/lib64/python2.7/logging/config.py", line 78, in fileConfig Jan 17 17:26:39 spiceqe.brq.redhat.com ovirt-imageio-daemon[18192]: handlers = _install_handlers(cp, formatters) Jan 17 17:26:39 spiceqe.brq.redhat.com ovirt-imageio-daemon[18192]: File "/usr/lib64/python2.7/logging/config.py", line 156, in _install_handlers Jan 17 17:26:39 spiceqe.brq.redhat.com ovirt-imageio-daemon[18192]: h = klass(*args) Jan 17 17:26:39 spiceqe.brq.redhat.com ovirt-imageio-daemon[18192]: File "/usr/lib64/python2.7/logging/handlers.py", line 117, in __init__ Jan 17 17:26:39 spiceqe.brq.redhat.com ovirt-imageio-daemon[18192]: BaseRotatingHandler.__init__(self, filename, mode, encoding, delay) Jan 17 17:26:39 spiceqe.brq.redhat.com ovirt-imageio-daemon[18192]: File "/usr/lib64/python2.7/logging/handlers.py", line 64, in __init__ Jan 17 17:26:39 spiceqe.brq.redhat.com ovirt-imageio-daemon[18192]: logging.FileHandler.__init__(self, filename, mode, encoding, delay) Jan 17 17:26:39 spiceqe.brq.redhat.com ovirt-imageio-daemon[18192]: File "/usr/lib64/python2.7/logging/__init__.py", line 902, in __init__ Jan 17 17:26:39 spiceqe.brq.redhat.com ovirt-imageio-daemon[18192]: StreamHandler.__init__(self, self._open()) Jan 17 17:26:39 spiceqe.brq.redhat.com ovirt-imageio-daemon[18192]: File "/usr/lib64/python2.7/logging/__init__.py", line 925, in _open Jan 17 17:26:39 spiceqe.brq.redhat.com ovirt-imageio-daemon[18192]: stream = open(self.baseFilename, self.mode) Jan 17 17:26:39 spiceqe.brq.redhat.com ovirt-imageio-daemon[18192]: IOError: [Errno 13] Permission denied: '/var/log/ovirt-imageio-daemon/daemon.log' Jan 17 17:26:39 spiceqe.brq.redhat.com systemd[1]: ovirt-imageio-daemon.service: main process exited, code=exited, status=1/FAILURE Jan 17 17:26:39 spiceqe.brq.redhat.com systemd[1]: Failed to start oVirt ImageIO Daemon. -- Subject: Unit ovirt-imageio-daemon.service has failed -- Defined-By: systemd -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel -- -- Unit ovirt-imageio-daemon.service has failed. -- -- The result is failed. Jan 17 17:26:39 spiceqe.brq.redhat.com systemd[1]: Unit ovirt-imageio-daemon.service entered failed state. Jan 17 17:26:39 spiceqe.brq.redhat.com systemd[1]: ovirt-imageio-daemon.service failed. Jan 17 17:26:39 spiceqe.brq.redhat.com systemd[1]: ovirt-imageio-daemon.service holdoff time over, scheduling restart. Jan 17 17:26:39 spiceqe.brq.redhat.com systemd[1]: start request repeated too quickly for ovirt-imageio-daemon.service Jan 17 17:26:39 spiceqe.brq.redhat.com systemd[1]: Failed to start oVirt ImageIO Daemon. -- Subject: Unit ovirt-imageio-daemon.service has failed -- Defined-By: systemd -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel -- -- Unit ovirt-imageio-daemon.service has failed. -- -- The result is failed. Jan 17 17:26:39 spiceqe.brq.redhat.com systemd[1]: Unit ovirt-imageio-daemon.service entered failed state. Jan 17 17:26:39 spiceqe.brq.redhat.com systemd[1]: ovirt-imageio-daemon.service failed.
Andrei, can you supply steps to reproduce?
Created attachment 1241938 [details] answer file for engine-setup
I got this error after: 1. systemctl stop ovirt-engine 2. make sure that answer file has next line set to True: OVESETUP_CONFIG/imageioProxyConfig=bool:True 1. configure engine with: engine-setup --config-append=1.answer (see attachment https://bugzilla.redhat.com/attachment.cgi?id=1241938) 2. systemctl start ovirt-engine 3. Go to admin portal 4. Select tab: "Storage" -> select storage -> select tab(at bottom) "Disk" -> "Upload" (4. or Select tab: "Disk" -> "Upload") 5. Select qcow2 image from your computer. "Events" tab gets message: VDSM spiceqe command failed: Cannot communicate with image daemon: 'reason=Error communicating with ovirt-imageio-daemon: [Errno 2] No such file or directory' 6. ssh to host: systemctl status ovirt-imageio-daemon ● ovirt-imageio-daemon.service - oVirt ImageIO Daemon Loaded: loaded (/usr/lib/systemd/system/ovirt-imageio-daemon.service; enabled; vendor preset: disabled) Active: failed (Result: start-limit) since Tue 2017-01-17 17:33:21 CET; 3h 11min ago Main PID: 18642 (code=exited, status=1/FAILURE) 7. -- Unit ovirt-imageio-daemon.service has begun starting up. Jan 17 20:50:58 spiceqe.brq.redhat.com ovirt-imageio-daemon[911]: Traceback (most recent call last): Jan 17 20:50:58 spiceqe.brq.redhat.com ovirt-imageio-daemon[911]: File "/usr/bin/ovirt-imageio-daemon", line 14, in <module> Jan 17 20:50:58 spiceqe.brq.redhat.com ovirt-imageio-daemon[911]: server.main(sys.argv) Jan 17 20:50:58 spiceqe.brq.redhat.com ovirt-imageio-daemon[911]: File "/usr/lib/python2.7/site-packages/ovirt_imageio_daemon/server.py", line 50, in main Jan 17 20:50:58 spiceqe.brq.redhat.com ovirt-imageio-daemon[911]: configure_logger() Jan 17 20:50:58 spiceqe.brq.redhat.com ovirt-imageio-daemon[911]: File "/usr/lib/python2.7/site-packages/ovirt_imageio_daemon/server.py", line 68, in configure_logger Jan 17 20:50:58 spiceqe.brq.redhat.com ovirt-imageio-daemon[911]: logging.config.fileConfig(conf, disable_existing_loggers=False) Jan 17 20:50:58 spiceqe.brq.redhat.com ovirt-imageio-daemon[911]: File "/usr/lib64/python2.7/logging/config.py", line 78, in fileConfig Jan 17 20:50:58 spiceqe.brq.redhat.com ovirt-imageio-daemon[911]: handlers = _install_handlers(cp, formatters) Jan 17 20:50:58 spiceqe.brq.redhat.com ovirt-imageio-daemon[911]: File "/usr/lib64/python2.7/logging/config.py", line 156, in _install_handlers Jan 17 20:50:58 spiceqe.brq.redhat.com ovirt-imageio-daemon[911]: h = klass(*args) Jan 17 20:50:58 spiceqe.brq.redhat.com ovirt-imageio-daemon[911]: File "/usr/lib64/python2.7/logging/handlers.py", line 117, in __init__ Jan 17 20:50:58 spiceqe.brq.redhat.com ovirt-imageio-daemon[911]: BaseRotatingHandler.__init__(self, filename, mode, encoding, delay) Jan 17 20:50:58 spiceqe.brq.redhat.com ovirt-imageio-daemon[911]: File "/usr/lib64/python2.7/logging/handlers.py", line 64, in __init__ Jan 17 20:50:58 spiceqe.brq.redhat.com ovirt-imageio-daemon[911]: logging.FileHandler.__init__(self, filename, mode, encoding, delay) Jan 17 20:50:58 spiceqe.brq.redhat.com ovirt-imageio-daemon[911]: File "/usr/lib64/python2.7/logging/__init__.py", line 902, in __init__ Jan 17 20:50:58 spiceqe.brq.redhat.com ovirt-imageio-daemon[911]: StreamHandler.__init__(self, self._open()) Jan 17 20:50:58 spiceqe.brq.redhat.com ovirt-imageio-daemon[911]: File "/usr/lib64/python2.7/logging/__init__.py", line 925, in _open Jan 17 20:50:58 spiceqe.brq.redhat.com ovirt-imageio-daemon[911]: stream = open(self.baseFilename, self.mode) Jan 17 20:50:58 spiceqe.brq.redhat.com ovirt-imageio-daemon[911]: IOError: [Errno 13] Permission denied: '/var/log/ovirt-imageio-daemon/daemon.log' Jan 17 20:50:58 spiceqe.brq.redhat.com systemd[1]: ovirt-imageio-daemon.service: main process exited, code=exited, status=1/FAILURE Jan 17 20:50:58 spiceqe.brq.redhat.com systemd[1]: Failed to start oVirt ImageIO Daemon. -- Subject: Unit ovirt-imageio-daemon.service has failed Additional info: Putting host to Maintenance + (Refresh capabilities OR Installation -> Reinstall) doesn't help to fix the bug.
Similar scenario as bug 1401901. Moving to MODIFIED for verification.
Verified using: ovirt-engine-4.1.0.3-0.1.el7.noarch ovirt-imageio-proxy-1.0.0-0.el7ev.noarch vdsm-4.19.4-1.el7ev.x86_64 ovirt-imageio-daemon-1.0.0-0.el7ev.noarch