Bug 1365451 - ovirt-imageio-proxy service failed to start after engine upgrade
Summary: ovirt-imageio-proxy service failed to start after engine upgrade
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: ovirt-engine
Classification: oVirt
Component: PKI
Version: 4.0.2.4
Hardware: Unspecified
OS: Unspecified
high
unspecified
Target Milestone: ovirt-4.0.3
: 4.0.3
Assignee: Yedidyah Bar David
QA Contact: Aleksei Slaikovskii
URL:
Whiteboard:
Depends On:
Blocks: 1365744
TreeView+ depends on / blocked
 
Reported: 2016-08-09 09:53 UTC by Barak Korren
Modified: 2019-12-16 06:20 UTC (History)
14 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Cause: PKI (key/cert) was not generated for ovirt-imageio-proxy by engine-setup during upgrade from earlier version. Consequence: ovirt-imageio-proxy service failed to start. Fix: engine-setup was changed to generate pki for all components also on upgrade, if missing. Result: The service now starts successfully.
Clone Of:
Environment:
Last Closed: 2016-08-29 14:50:50 UTC
oVirt Team: Integration
Embargoed:
rule-engine: ovirt-4.0.z+
rule-engine: blocker+
ylavi: planning_ack+
sbonazzo: devel_ack+
pstehlik: testing_ack+


Attachments (Terms of Use)
first engine-setup log (2.44 MB, text/plain)
2016-08-09 09:53 UTC, Barak Korren
no flags Details
2nd engine-setup log (2.33 MB, text/plain)
2016-08-09 09:55 UTC, Barak Korren
no flags Details


Links
System ID Private Priority Status Summary Last Updated
oVirt gerrit 62188 0 master MERGED packaging: setup: Enroll missing pki on upgrade 2021-02-03 20:42:48 UTC
oVirt gerrit 62230 0 ovirt-engine-4.0 MERGED packaging: setup: Enroll missing pki on upgrade 2021-02-03 20:42:48 UTC
oVirt gerrit 62307 0 master MERGED packaging: setup: Enroll missing pki on upgrade 2021-02-03 20:42:47 UTC
oVirt gerrit 62315 0 ovirt-engine-4.0 MERGED packaging: setup: Enroll missing pki on upgrade 2021-02-03 20:42:48 UTC
oVirt gerrit 62316 0 master MERGED Revert "packaging: setup: Enroll missing pki on upgrade" 2021-02-03 20:42:48 UTC
oVirt gerrit 62317 0 ovirt-engine-4.0 MERGED Revert "packaging: setup: Enroll missing pki on upgrade" 2021-02-03 20:42:48 UTC
oVirt gerrit 62326 0 ovirt-engine-4.0.0 ABANDONED packaging: setup: Enroll missing pki on upgrade 2021-02-03 20:42:48 UTC
oVirt gerrit 62396 0 ovirt-engine-4.0.2 MERGED packaging: setup: Enroll missing pki on upgrade 2021-02-03 20:42:48 UTC

Description Barak Korren 2016-08-09 09:53:59 UTC
Created attachment 1189181 [details]
first engine-setup log

Description of problem:
ovirt-imageio-proxy service failed to start after engine upgrade

Version-Release number of selected component (if applicable):
ovirt-imageio-proxy-0.3.0-0
ovirt-engine updated from 4.0.1.1-0.1 to 4.0.2.4-0.1

Steps to Reproduce:
1. Have an engine host installed with ovirt-engine-4.0.1.1-0.1 (4.0.1-2 rhev build)
2. Change system repos to point to newer build (4.0.2-6 rhev build)
3. Upgrade engine-setup-* and ovirt-engine-dwh-setup packages
4. run engine-setup to perform engine upgrade
5. run "yum update" to update any other OS packages that may need updating
6. run engine-setup again

Actual results:
The 2nd engine setup run fails with the following error:
[ ERROR ] Failed to execute stage 'Closing up': Failed to start service 'ovirt-imageio-proxy'

The 'ovirt-imageio-proxy' indeed fails to be stated with the following lines showing up in /var/log/messages:

systemd: Stopped oVirt ImageIO Proxy.
systemd: Starting oVirt ImageIO Proxy...
ovirt-imageio-proxy: Traceback (most recent call last):
ovirt-imageio-proxy: File "/usr/bin/ovirt-imageio-proxy", line 85, in <module>
ovirt-imageio-proxy: status = image_proxy.main(args, config)
ovirt-imageio-proxy: File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/image_proxy.py", line 21, in main
ovirt-imageio-proxy: image_server.start(config)
ovirt-imageio-proxy: File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/server.py", line 45, in start
ovirt-imageio-proxy: self._secure_server(config, server)
ovirt-imageio-proxy: File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/server.py", line 62, in _secure_server
ovirt-imageio-proxy: server_side=True)
ovirt-imageio-proxy: File "/usr/lib64/python2.7/ssl.py", line 913, in wrap_socket
ovirt-imageio-proxy: ciphers=ciphers)
ovirt-imageio-proxy: File "/usr/lib64/python2.7/ssl.py", line 526, in __init__
ovirt-imageio-proxy: self._context.load_cert_chain(certfile, keyfile)
ovirt-imageio-proxy: IOError: [Errno 2] No such file or directory
systemd: ovirt-imageio-proxy.service: main process exited, code=exited, status=1/FAILURE
systemd: Failed to start oVirt ImageIO Proxy.
systemd: Unit ovirt-imageio-proxy.service entered failed state.
systemd: ovirt-imageio-proxy.service failed.


Expected results:
The service should start successfully

Additional info:
Attached logs of both engine-setup runs

Comment 1 Barak Korren 2016-08-09 09:55:29 UTC
Created attachment 1189187 [details]
2nd engine-setup log

Comment 2 Eyal Edri 2016-08-10 07:16:53 UTC
Do we know if this would fail also from 3.6 to 4.0.2?
If it does, then I think we should consider it as a blocker to 4.0.2

Comment 3 Barak Korren 2016-08-10 07:40:18 UTC
AFAIK this will not fail the upgrade itself (that would be the 1st 'engine-setup' run) but:
1. Trying to run subsequent upgrades will fail (2nd engine-setup run)
2. ovirt-imageio-proxy will not be configured by the upgrade process, so image uploading may not work after upgrade.

Comment 4 Yedidyah Bar David 2016-08-10 08:56:15 UTC
(In reply to Barak Korren from comment #0)
> ovirt-imageio-proxy: self._context.load_cert_chain(certfile, keyfile)
> ovirt-imageio-proxy: IOError: [Errno 2] No such file or directory

pki is missing.

The code in imageio-proxy setup plugin has this:

# If on same host as engine, engine setup code creates pki for us

But this is not accurate. On upgrade, if pki needs to be renewed, and some keys/certs are missing, we also generate them. But if not renewing, we also do not generate on upgrade.

Possible solutions:
1. Make the common code (in engine plugin) generate missing keys/certs also on upgrade.
2. Make imageio-proxy setup plugin handle pki always, not only on upgrade. Check if key exists and generate otherwise.

I think latter makes more sense.

Same issue affects in principle also websocket-proxy pki. The reason it does not happen in practice is that it was introduced long ago, where behavior was different.

Comment 5 Allon Mureinik 2016-08-11 09:02:03 UTC
The meaning of this bug is that you cannot get ovirt-imageio in an upgraded system (or worse - if you select YES when configuring it, it will fail the setup!) I think we should consider this for 4.0.3 and not wait for 4.0.4.

Comment 6 Sandro Bonazzola 2016-08-11 10:19:52 UTC
(In reply to Allon Mureinik from comment #5)
> The meaning of this bug is that you cannot get ovirt-imageio in an upgraded
> system (or worse - if you select YES when configuring it, it will fail the
> setup!) I think we should consider this for 4.0.3 and not wait for 4.0.4.

So you're candidating this to be a blocker. I'm re-targeting to 4.0.3 and proposing as blocker.

Comment 7 Yedidyah Bar David 2016-08-11 10:23:53 UTC
Note for QE:

This is a somewhat delicate change. Please consider also the following flows:

- Upgrade from 3.4 (earlier is better) -> 3.5 -> 3.6 -> 4.0
- Upgrade from a system with certs from 4.5 years ago, and choose to not renew certs until 3.6 -> 4.0

Please attach to the bug all setup logs and ls -lR /etc/pki/ovirt-engine /etc/ovirt-engine. In particular, please make sure that only pki files that where supposed to be added/changed, are indeed added/changed, and not others.

Thanks.

Comment 8 Sandro Bonazzola 2016-08-12 05:07:54 UTC
I guess we'll create 4.0.3 branch out of 4.0.2 one instead of from 4.0 so please keep this on POST until we branch and backport the patches to that branch.

Comment 9 Allon Mureinik 2016-08-14 11:36:38 UTC
(In reply to Sandro Bonazzola from comment #8)
> I guess we'll create 4.0.3 branch out of 4.0.2 one instead of from 4.0 so
> please keep this on POST until we branch and backport the patches to that
> branch.

Actually, if there's a 4.0.2 respin, shouldn't we have it there? Wouldn't it be /less/ of a hassle/risk than having a 4.0.3 branch?

Comment 10 Sandro Bonazzola 2016-08-14 11:58:32 UTC
No problem to go with a 4.0.2 async on my side.

Comment 11 Eyal Edri 2016-08-14 13:25:34 UTC
4.0.2 async == 4.0.3, and it is RSVP for critical and urgent issues.
If this is the case, then we can consider re-targeting it.

Comment 12 Jiri Belka 2016-08-18 14:17:07 UTC
(In reply to Barak Korren from comment #0)
> Created attachment 1189181 [details]
> first engine-setup log
> 
> Description of problem:
> ovirt-imageio-proxy service failed to start after engine upgrade
> 
> Version-Release number of selected component (if applicable):
> ovirt-imageio-proxy-0.3.0-0
> ovirt-engine updated from 4.0.1.1-0.1 to 4.0.2.4-0.1
> 
> Steps to Reproduce:
> 1. Have an engine host installed with ovirt-engine-4.0.1.1-0.1 (4.0.1-2 rhev
> build)
> 2. Change system repos to point to newer build (4.0.2-6 rhev build)
> 3. Upgrade engine-setup-* and ovirt-engine-dwh-setup packages
> 4. run engine-setup to perform engine upgrade
> 5. run "yum update" to update any other OS packages that may need updating
> 6. run engine-setup again
> 
> Actual results:
> The 2nd engine setup run fails with the following error:
> [ ERROR ] Failed to execute stage 'Closing up': Failed to start service
> 'ovirt-imageio-proxy'
> 
> The 'ovirt-imageio-proxy' indeed fails to be stated with the following lines
> showing up in /var/log/messages:
> 
> systemd: Stopped oVirt ImageIO Proxy.
> systemd: Starting oVirt ImageIO Proxy...
> ovirt-imageio-proxy: Traceback (most recent call last):
> ovirt-imageio-proxy: File "/usr/bin/ovirt-imageio-proxy", line 85, in
> <module>
> ovirt-imageio-proxy: status = image_proxy.main(args, config)
> ovirt-imageio-proxy: File
> "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/image_proxy.py", line
> 21, in main
> ovirt-imageio-proxy: image_server.start(config)
> ovirt-imageio-proxy: File
> "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/server.py", line 45,
> in start
> ovirt-imageio-proxy: self._secure_server(config, server)
> ovirt-imageio-proxy: File
> "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/server.py", line 62,
> in _secure_server
> ovirt-imageio-proxy: server_side=True)
> ovirt-imageio-proxy: File "/usr/lib64/python2.7/ssl.py", line 913, in
> wrap_socket
> ovirt-imageio-proxy: ciphers=ciphers)
> ovirt-imageio-proxy: File "/usr/lib64/python2.7/ssl.py", line 526, in
> __init__
> ovirt-imageio-proxy: self._context.load_cert_chain(certfile, keyfile)
> ovirt-imageio-proxy: IOError: [Errno 2] No such file or directory
> systemd: ovirt-imageio-proxy.service: main process exited, code=exited,
> status=1/FAILURE
> systemd: Failed to start oVirt ImageIO Proxy.
> systemd: Unit ovirt-imageio-proxy.service entered failed state.
> systemd: ovirt-imageio-proxy.service failed.
> 
> 
> Expected results:
> The service should start successfully
> 
> Additional info:
> Attached logs of both engine-setup runs

I used my own signed certs and I face same issue, what is the workaround please?

Also running this with --stdout debug it could print path to config and logger config:

[root@jb-rhevm40 ~]# /usr/bin/ovirt-imageio-proxy --stdout debug                                          
XXX /etc/ovirt-imageio-proxy/logger.conf
XXX /etc/ovirt-imageio-proxy/ovirt-imageio-proxy.conf
(MainThread) DEBUG root:Configuration value port = 54323
(MainThread) DEBUG root:Configuration value host = 
(MainThread) DEBUG root:Configuration value use_ssl = true
(MainThread) DEBUG root:Configuration value ssl_key_file = /etc/pki/ovirt-engine/keys/imageio-proxy.key.no
pass
(MainThread) DEBUG root:Configuration value ssl_cert_file = /etc/pki/ovirt-engine/certs/imageio-proxy.cer
(MainThread) DEBUG root:Configuration value engine_cert_file = /etc/pki/ovirt-engine/certs/engine.cer
(MainThread) DEBUG root:Configuration value engine_ca_cert_file = /etc/pki/ovirt-engine/ca.pem
(MainThread) DEBUG root:Configuration value verify_certificate = true
Traceback (most recent call last):
  File "/usr/bin/ovirt-imageio-proxy", line 87, in <module>
    status = image_proxy.main(args, config)
  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/image_proxy.py", line 21, in main
    image_server.start(config)
  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/server.py", line 45, in start
    self._secure_server(config, server)
  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/server.py", line 62, in _secure_server
    server_side=True)
  File "/usr/lib64/python2.7/ssl.py", line 913, in wrap_socket
    ciphers=ciphers)
  File "/usr/lib64/python2.7/ssl.py", line 526, in __init__
    self._context.load_cert_chain(certfile, keyfile)
IOError: [Errno 2] No such file or directory

[root@jb-rhevm40 ~]# grep XXX /usr/bin/ovirt-imageio-proxy
print "XXX " + constants.LOG_CONF_FILE
print "XXX " + constants.CONFIG_FILE

Comment 13 Amit Aviram 2016-08-18 15:32:03 UTC
(In reply to Jiri Belka from comment #12)
> (In reply to Barak Korren from comment #0)
> > Created attachment 1189181 [details]
> > first engine-setup log
> > 
> > Description of problem:
> > ovirt-imageio-proxy service failed to start after engine upgrade
> > 
> > Version-Release number of selected component (if applicable):
> > ovirt-imageio-proxy-0.3.0-0
> > ovirt-engine updated from 4.0.1.1-0.1 to 4.0.2.4-0.1
> > 
> > Steps to Reproduce:
> > 1. Have an engine host installed with ovirt-engine-4.0.1.1-0.1 (4.0.1-2 rhev
> > build)
> > 2. Change system repos to point to newer build (4.0.2-6 rhev build)
> > 3. Upgrade engine-setup-* and ovirt-engine-dwh-setup packages
> > 4. run engine-setup to perform engine upgrade
> > 5. run "yum update" to update any other OS packages that may need updating
> > 6. run engine-setup again
> > 
> > Actual results:
> > The 2nd engine setup run fails with the following error:
> > [ ERROR ] Failed to execute stage 'Closing up': Failed to start service
> > 'ovirt-imageio-proxy'
> > 
> > The 'ovirt-imageio-proxy' indeed fails to be stated with the following lines
> > showing up in /var/log/messages:
> > 
> > systemd: Stopped oVirt ImageIO Proxy.
> > systemd: Starting oVirt ImageIO Proxy...
> > ovirt-imageio-proxy: Traceback (most recent call last):
> > ovirt-imageio-proxy: File "/usr/bin/ovirt-imageio-proxy", line 85, in
> > <module>
> > ovirt-imageio-proxy: status = image_proxy.main(args, config)
> > ovirt-imageio-proxy: File
> > "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/image_proxy.py", line
> > 21, in main
> > ovirt-imageio-proxy: image_server.start(config)
> > ovirt-imageio-proxy: File
> > "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/server.py", line 45,
> > in start
> > ovirt-imageio-proxy: self._secure_server(config, server)
> > ovirt-imageio-proxy: File
> > "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/server.py", line 62,
> > in _secure_server
> > ovirt-imageio-proxy: server_side=True)
> > ovirt-imageio-proxy: File "/usr/lib64/python2.7/ssl.py", line 913, in
> > wrap_socket
> > ovirt-imageio-proxy: ciphers=ciphers)
> > ovirt-imageio-proxy: File "/usr/lib64/python2.7/ssl.py", line 526, in
> > __init__
> > ovirt-imageio-proxy: self._context.load_cert_chain(certfile, keyfile)
> > ovirt-imageio-proxy: IOError: [Errno 2] No such file or directory
> > systemd: ovirt-imageio-proxy.service: main process exited, code=exited,
> > status=1/FAILURE
> > systemd: Failed to start oVirt ImageIO Proxy.
> > systemd: Unit ovirt-imageio-proxy.service entered failed state.
> > systemd: ovirt-imageio-proxy.service failed.
> > 
> > 
> > Expected results:
> > The service should start successfully
> > 
> > Additional info:
> > Attached logs of both engine-setup runs
> 
> I used my own signed certs and I face same issue, what is the workaround
> please?
> 
> Also running this with --stdout debug it could print path to config and
> logger config:
> 
> [root@jb-rhevm40 ~]# /usr/bin/ovirt-imageio-proxy --stdout debug            
> 
> XXX /etc/ovirt-imageio-proxy/logger.conf
> XXX /etc/ovirt-imageio-proxy/ovirt-imageio-proxy.conf
> (MainThread) DEBUG root:Configuration value port = 54323
> (MainThread) DEBUG root:Configuration value host = 
> (MainThread) DEBUG root:Configuration value use_ssl = true
> (MainThread) DEBUG root:Configuration value ssl_key_file =
> /etc/pki/ovirt-engine/keys/imageio-proxy.key.no
> pass
> (MainThread) DEBUG root:Configuration value ssl_cert_file =
> /etc/pki/ovirt-engine/certs/imageio-proxy.cer
> (MainThread) DEBUG root:Configuration value engine_cert_file =
> /etc/pki/ovirt-engine/certs/engine.cer
> (MainThread) DEBUG root:Configuration value engine_ca_cert_file =
> /etc/pki/ovirt-engine/ca.pem
> (MainThread) DEBUG root:Configuration value verify_certificate = true
> Traceback (most recent call last):
>   File "/usr/bin/ovirt-imageio-proxy", line 87, in <module>
>     status = image_proxy.main(args, config)
>   File
> "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/image_proxy.py", line
> 21, in main
>     image_server.start(config)
>   File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/server.py",
> line 45, in start
>     self._secure_server(config, server)
>   File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/server.py",
> line 62, in _secure_server
>     server_side=True)
>   File "/usr/lib64/python2.7/ssl.py", line 913, in wrap_socket
>     ciphers=ciphers)
>   File "/usr/lib64/python2.7/ssl.py", line 526, in __init__
>     self._context.load_cert_chain(certfile, keyfile)
> IOError: [Errno 2] No such file or directory
> 
> [root@jb-rhevm40 ~]# grep XXX /usr/bin/ovirt-imageio-proxy
> print "XXX " + constants.LOG_CONF_FILE
> print "XXX " + constants.CONFIG_FILE

You probably don't have the imageio-proxy keys. for workaround, you can use the keys generated for other services, like "reports". edit imageio configuration file and use this service's keys:

- vim /etc/ovirt-imageio-proxy/ovirt-imageio-proxy.conf
- :%s/imageio-proxy/resports/

(Assuming that ovirt-engine is installed regularly, and its keys are in /etc/pki/ovirt-engine)

Please let me know if that works out for you. also, make sure the engine's CA is added to the authorities list in your browser.

Comment 14 Amit Aviram 2016-08-18 15:33:28 UTC
(In reply to Amit Aviram from comment #13)
> (In reply to Jiri Belka from comment #12)
> > (In reply to Barak Korren from comment #0)
> > > Created attachment 1189181 [details]
> > > first engine-setup log
> > > 
> > > Description of problem:
> > > ovirt-imageio-proxy service failed to start after engine upgrade
> > > 
> > > Version-Release number of selected component (if applicable):
> > > ovirt-imageio-proxy-0.3.0-0
> > > ovirt-engine updated from 4.0.1.1-0.1 to 4.0.2.4-0.1
> > > 
> > > Steps to Reproduce:
> > > 1. Have an engine host installed with ovirt-engine-4.0.1.1-0.1 (4.0.1-2 rhev
> > > build)
> > > 2. Change system repos to point to newer build (4.0.2-6 rhev build)
> > > 3. Upgrade engine-setup-* and ovirt-engine-dwh-setup packages
> > > 4. run engine-setup to perform engine upgrade
> > > 5. run "yum update" to update any other OS packages that may need updating
> > > 6. run engine-setup again
> > > 
> > > Actual results:
> > > The 2nd engine setup run fails with the following error:
> > > [ ERROR ] Failed to execute stage 'Closing up': Failed to start service
> > > 'ovirt-imageio-proxy'
> > > 
> > > The 'ovirt-imageio-proxy' indeed fails to be stated with the following lines
> > > showing up in /var/log/messages:
> > > 
> > > systemd: Stopped oVirt ImageIO Proxy.
> > > systemd: Starting oVirt ImageIO Proxy...
> > > ovirt-imageio-proxy: Traceback (most recent call last):
> > > ovirt-imageio-proxy: File "/usr/bin/ovirt-imageio-proxy", line 85, in
> > > <module>
> > > ovirt-imageio-proxy: status = image_proxy.main(args, config)
> > > ovirt-imageio-proxy: File
> > > "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/image_proxy.py", line
> > > 21, in main
> > > ovirt-imageio-proxy: image_server.start(config)
> > > ovirt-imageio-proxy: File
> > > "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/server.py", line 45,
> > > in start
> > > ovirt-imageio-proxy: self._secure_server(config, server)
> > > ovirt-imageio-proxy: File
> > > "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/server.py", line 62,
> > > in _secure_server
> > > ovirt-imageio-proxy: server_side=True)
> > > ovirt-imageio-proxy: File "/usr/lib64/python2.7/ssl.py", line 913, in
> > > wrap_socket
> > > ovirt-imageio-proxy: ciphers=ciphers)
> > > ovirt-imageio-proxy: File "/usr/lib64/python2.7/ssl.py", line 526, in
> > > __init__
> > > ovirt-imageio-proxy: self._context.load_cert_chain(certfile, keyfile)
> > > ovirt-imageio-proxy: IOError: [Errno 2] No such file or directory
> > > systemd: ovirt-imageio-proxy.service: main process exited, code=exited,
> > > status=1/FAILURE
> > > systemd: Failed to start oVirt ImageIO Proxy.
> > > systemd: Unit ovirt-imageio-proxy.service entered failed state.
> > > systemd: ovirt-imageio-proxy.service failed.
> > > 
> > > 
> > > Expected results:
> > > The service should start successfully
> > > 
> > > Additional info:
> > > Attached logs of both engine-setup runs
> > 
> > I used my own signed certs and I face same issue, what is the workaround
> > please?
> > 
> > Also running this with --stdout debug it could print path to config and
> > logger config:
> > 
> > [root@jb-rhevm40 ~]# /usr/bin/ovirt-imageio-proxy --stdout debug            
> > 
> > XXX /etc/ovirt-imageio-proxy/logger.conf
> > XXX /etc/ovirt-imageio-proxy/ovirt-imageio-proxy.conf
> > (MainThread) DEBUG root:Configuration value port = 54323
> > (MainThread) DEBUG root:Configuration value host = 
> > (MainThread) DEBUG root:Configuration value use_ssl = true
> > (MainThread) DEBUG root:Configuration value ssl_key_file =
> > /etc/pki/ovirt-engine/keys/imageio-proxy.key.no
> > pass
> > (MainThread) DEBUG root:Configuration value ssl_cert_file =
> > /etc/pki/ovirt-engine/certs/imageio-proxy.cer
> > (MainThread) DEBUG root:Configuration value engine_cert_file =
> > /etc/pki/ovirt-engine/certs/engine.cer
> > (MainThread) DEBUG root:Configuration value engine_ca_cert_file =
> > /etc/pki/ovirt-engine/ca.pem
> > (MainThread) DEBUG root:Configuration value verify_certificate = true
> > Traceback (most recent call last):
> >   File "/usr/bin/ovirt-imageio-proxy", line 87, in <module>
> >     status = image_proxy.main(args, config)
> >   File
> > "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/image_proxy.py", line
> > 21, in main
> >     image_server.start(config)
> >   File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/server.py",
> > line 45, in start
> >     self._secure_server(config, server)
> >   File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/server.py",
> > line 62, in _secure_server
> >     server_side=True)
> >   File "/usr/lib64/python2.7/ssl.py", line 913, in wrap_socket
> >     ciphers=ciphers)
> >   File "/usr/lib64/python2.7/ssl.py", line 526, in __init__
> >     self._context.load_cert_chain(certfile, keyfile)
> > IOError: [Errno 2] No such file or directory
> > 
> > [root@jb-rhevm40 ~]# grep XXX /usr/bin/ovirt-imageio-proxy
> > print "XXX " + constants.LOG_CONF_FILE
> > print "XXX " + constants.CONFIG_FILE
> 
> You probably don't have the imageio-proxy keys. for workaround, you can use
> the keys generated for other services, like "reports". edit imageio
> configuration file and use this service's keys:
> 
> - vim /etc/ovirt-imageio-proxy/ovirt-imageio-proxy.conf
> - :%s/imageio-proxy/resports/


******* correction: that should be "reports" and not "resports" (make sure you have this file)

> 
> (Assuming that ovirt-engine is installed regularly, and its keys are in
> /etc/pki/ovirt-engine)
> 
> Please let me know if that works out for you. also, make sure the engine's
> CA is added to the authorities list in your browser.

Comment 15 Radek Duda 2016-08-19 08:14:50 UTC
I tried to change values in the file
> - vim /etc/ovirt-imageio-proxy/ovirt-imageio-proxy.conf
> - :%s/imageio-proxy/reports/

then
# systemctl restart ovirt-imageio-proxy.service
and service is activated
nevertheless if
#  /usr/bin/ovirt-imageio-proxy --stdout debug 
(MainThread) DEBUG root:Configuration value port = 54323
(MainThread) DEBUG root:Configuration value host = 
(MainThread) DEBUG root:Configuration value use_ssl = true
(MainThread) DEBUG root:Configuration value ssl_key_file = /etc/pki/ovirt-engine/keys/reports.key.nopass
(MainThread) DEBUG root:Configuration value ssl_cert_file = /etc/pki/ovirt-engine/certs/reports.cer
(MainThread) DEBUG root:Configuration value engine_cert_file = /etc/pki/ovirt-engine/certs/engine.cer
(MainThread) DEBUG root:Configuration value engine_ca_cert_file = /etc/pki/ovirt-engine/ca.pem
(MainThread) DEBUG root:Configuration value verify_certificate = true
(MainThread) INFO root:Server started, unable to notify systemd

..and nothing happens

If I run engine-setup, the values in file /etc/ovirt-imageio-proxy/ovirt-imageio-proxy.conf are rewritten back.

Comment 16 Jiri Belka 2016-08-20 04:45:17 UTC
Uff, every run of engine-setup regenerates this config file, thus manual workaround is dropped again.

Comment 17 Amit Aviram 2016-08-21 07:26:11 UTC
(In reply to Radek Duda from comment #15)
> I tried to change values in the file
> > - vim /etc/ovirt-imageio-proxy/ovirt-imageio-proxy.conf
> > - :%s/imageio-proxy/reports/
> 
> then
> # systemctl restart ovirt-imageio-proxy.service
> and service is activated

At this point you are ready to upload your image.

> nevertheless if
> #  /usr/bin/ovirt-imageio-proxy --stdout debug 
> (MainThread) DEBUG root:Configuration value port = 54323
> (MainThread) DEBUG root:Configuration value host = 
> (MainThread) DEBUG root:Configuration value use_ssl = true
> (MainThread) DEBUG root:Configuration value ssl_key_file =
> /etc/pki/ovirt-engine/keys/reports.key.nopass
> (MainThread) DEBUG root:Configuration value ssl_cert_file =
> /etc/pki/ovirt-engine/certs/reports.cer
> (MainThread) DEBUG root:Configuration value engine_cert_file =
> /etc/pki/ovirt-engine/certs/engine.cer
> (MainThread) DEBUG root:Configuration value engine_ca_cert_file =
> /etc/pki/ovirt-engine/ca.pem
> (MainThread) DEBUG root:Configuration value verify_certificate = true
> (MainThread) INFO root:Server started, unable to notify systemd
> 

Right, because the service runs and waits for requests. you will start see them when you'll start upload.

> 
> If I run engine-setup, the values in file
> /etc/ovirt-imageio-proxy/ovirt-imageio-proxy.conf are rewritten back.
Assuming you don't need to setup over and over again, maybe this workaround is enough until you'll update your version.

Btw, you can also just copy reports.key.nopass and reports.cer and call it imageio-proxy.key.nopass and imageio-proxy.cer, and then running setup won't ruin your modified env. might be easiest.

Comment 18 Jiri Belka 2016-08-23 06:40:33 UTC
(In reply to Amit Aviram from comment #17)
> (In reply to Radek Duda from comment #15)
> > I tried to change values in the file
> > > - vim /etc/ovirt-imageio-proxy/ovirt-imageio-proxy.conf
> > > - :%s/imageio-proxy/reports/
> > 
> > then
> > # systemctl restart ovirt-imageio-proxy.service
> > and service is activated
> 
> At this point you are ready to upload your image.
> 
> > nevertheless if
> > #  /usr/bin/ovirt-imageio-proxy --stdout debug 
> > (MainThread) DEBUG root:Configuration value port = 54323
> > (MainThread) DEBUG root:Configuration value host = 
> > (MainThread) DEBUG root:Configuration value use_ssl = true
> > (MainThread) DEBUG root:Configuration value ssl_key_file =
> > /etc/pki/ovirt-engine/keys/reports.key.nopass
> > (MainThread) DEBUG root:Configuration value ssl_cert_file =
> > /etc/pki/ovirt-engine/certs/reports.cer
> > (MainThread) DEBUG root:Configuration value engine_cert_file =
> > /etc/pki/ovirt-engine/certs/engine.cer
> > (MainThread) DEBUG root:Configuration value engine_ca_cert_file =
> > /etc/pki/ovirt-engine/ca.pem
> > (MainThread) DEBUG root:Configuration value verify_certificate = true
> > (MainThread) INFO root:Server started, unable to notify systemd
> > 
> 
> Right, because the service runs and waits for requests. you will start see
> them when you'll start upload.
> 
> > 
> > If I run engine-setup, the values in file
> > /etc/ovirt-imageio-proxy/ovirt-imageio-proxy.conf are rewritten back.
> Assuming you don't need to setup over and over again, maybe this workaround
> is enough until you'll update your version.
> 
> Btw, you can also just copy reports.key.nopass and reports.cer and call it
> imageio-proxy.key.nopass and imageio-proxy.cer, and then running setup won't
> ruin your modified env. might be easiest.

It works for me, I used websocket keys instead.

Anyway, I was little bit confused that the config file is not under /etc/ovirt-engine as it is the case for all other engine's applications.

Comment 19 Gianluca Cecchi 2016-08-26 10:38:59 UTC
Hello, some comments on my side.
1) If I put in ovirt-imageio-proxy.conf 
use_ssl = false

anyway the upload of a qcow2 image initializes and then remains in paused.
I only see a new 443 socket opened from client where browser is run, towards the engine ip.
On engine the port 54323 remains listening but no connection at all opened at that port...
Does this mean that despite of "use_ssl" parameter in conf file, SSL is in any way actually forced?

2) Modifying ovirt-imageio-proxy.conf and putting

use_ssl = true

ssl_key_file = /etc/pki/ovirt-engine/keys/websocket-proxy.key.nopass

ssl_cert_file = /etc/pki/ovirt-engine/certs/websocket-proxy.cer

[root@ractorshe certs]# ll /etc/pki/ovirt-engine/keys/websocket-proxy*
-rw-------. 1 ovirt ovirt 1828 Nov 19  2015 /etc/pki/ovirt-engine/keys/websocket-proxy.key.nopass
-rw-------. 1 ovirt root  2805 Nov 19  2015 /etc/pki/ovirt-engine/keys/websocket-proxy.p12
[root@ractorshe certs]# 

and restarting the service 
again the upload initializes but then goes to pause.

This with these packages at the moment
ovirt-imageio-proxy-setup-0.3.0-0.201606191345.git9f3d6d4.el7.centos.noarch
ovirt-vmconsole-proxy-1.0.4-1.el7.centos.noarch
ovirt-imageio-proxy-0.3.0-0.201606191345.git9f3d6d4.el7.centos.noarch
ovirt-engine-vmconsole-proxy-helper-4.0.2.6-1.el7.centos.noarch
ovirt-engine-websocket-proxy-4.0.2.6-1.el7.centos.noarch

What version of the packages caused upload to work using websocket proxy keyes, as described in comment#18?
Thanks,
Gianluca

Comment 20 Amit Aviram 2016-08-28 08:27:36 UTC
(In reply to Gianluca Cecchi from comment #19)
> Hello, some comments on my side.
> 1) If I put in ovirt-imageio-proxy.conf 
> use_ssl = false
> 
> anyway the upload of a qcow2 image initializes and then remains in paused.
> I only see a new 443 socket opened from client where browser is run, towards
> the engine ip.

That is probably the connection to the engine itself.

> On engine the port 54323 remains listening but no connection at all opened
> at that port...
> Does this mean that despite of "use_ssl" parameter in conf file, SSL is in
> any way actually forced?

The browser sends SSL request, so there are some other configurations to do in order to set this value to false. You better leave it "True", and use the websocket keys.

> 
> 2) Modifying ovirt-imageio-proxy.conf and putting
> 
> use_ssl = true
> 
> ssl_key_file = /etc/pki/ovirt-engine/keys/websocket-proxy.key.nopass
> 
> ssl_cert_file = /etc/pki/ovirt-engine/certs/websocket-proxy.cer
> 
> [root@ractorshe certs]# ll /etc/pki/ovirt-engine/keys/websocket-proxy*
> -rw-------. 1 ovirt ovirt 1828 Nov 19  2015
> /etc/pki/ovirt-engine/keys/websocket-proxy.key.nopass
> -rw-------. 1 ovirt root  2805 Nov 19  2015
> /etc/pki/ovirt-engine/keys/websocket-proxy.p12
> [root@ractorshe certs]# 
> 
> and restarting the service 
> again the upload initializes but then goes to pause.

Did you install the engine's CA in your browser? you should download it from 
https://{Your engine's URL}/ovirt-engine/services/pki-resource?resource=ca-certificate&format=X509-PEM-CA

Can you attach the browser's console logs? and /var/log/ovirt-imageio-proxy/imageio-proxy.log file?

> 
> This with these packages at the moment
> ovirt-imageio-proxy-setup-0.3.0-0.201606191345.git9f3d6d4.el7.centos.noarch
> ovirt-vmconsole-proxy-1.0.4-1.el7.centos.noarch
> ovirt-imageio-proxy-0.3.0-0.201606191345.git9f3d6d4.el7.centos.noarch
> ovirt-engine-vmconsole-proxy-helper-4.0.2.6-1.el7.centos.noarch
> ovirt-engine-websocket-proxy-4.0.2.6-1.el7.centos.noarch
> 
> What version of the packages caused upload to work using websocket proxy
> keyes, as described in comment#18?

Not a specific version- it is just a workaround for this bug to have the upload working.

Amit

Comment 21 Gianluca Cecchi 2016-08-29 07:53:44 UTC
Tried and installed CA.
But I get the same behavior (SSL enabled).
The sequence of what I see in web admin page:
locked 
initializing 
sent 0 of 1551 Mb
Paused by System

then I can cancel upload and remove disk

image-proxy.log only contains start line:

(MainThread) INFO 2016-08-26 16:40:50,718 image_proxy:26:root:(main) Server started, successfully notified systemd

How to provide browser console log instead?
BTW: my browser is firefox-45.1.0-1.0.1.el6_7.x86_64 on a CentOS 6.6 system

Comment 22 Gianluca Cecchi 2016-08-29 08:01:10 UTC
When I select to Cancel upload I see:
Cancelled
Finalizing Failure
Illegal

Then with remove:
Locked
disk line goes away

Sequence of what I see in engine.log, right after pressing OK in upload disk window:
2016-08-29 09:58:05,741 INFO  [org.ovirt.engine.core.bll.storage.disk.image.UploadDiskImageCommand] (default task-56) [114b51be] Running command: UploadDiskImageCommand internal: false. Entities affected :  ID: 556abaa8-0fcc-4042-963b-f27db5e03837 Type: StorageAction group CREATE_DISK with role type USER
2016-08-29 09:58:05,742 INFO  [org.ovirt.engine.core.bll.storage.disk.image.UploadDiskImageCommand] (default task-56) [114b51be] Creating ImageTransfer entity for command '58473169-c5b9-4c67-84f2-69b54226f84c'
2016-08-29 09:58:05,754 INFO  [org.ovirt.engine.core.bll.storage.disk.image.UploadDiskImageCommand] (default task-56) [114b51be] Creating disk image
2016-08-29 09:58:05,843 INFO  [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (pool-7-thread-5) [246dd4a8] Running command: AddDiskCommand internal: true. Entities affected :  ID: 556abaa8-0fcc-4042-963b-f27db5e03837 Type: StorageAction group CREATE_DISK with role type USER
2016-08-29 09:58:05,854 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-56) [] Correlation ID: 114b51be, Call Stack: null, Custom Event ID: -1, Message: Upload image to disk aaa was initiated by admin@internal-authz.
2016-08-29 09:58:05,909 INFO  [org.ovirt.engine.core.bll.storage.disk.image.AddImageFromScratchCommand] (pool-7-thread-5) [405bc4cf] Running command: AddImageFromScratchCommand internal: true. Entities affected :  ID: 556abaa8-0fcc-4042-963b-f27db5e03837 Type: Storage
2016-08-29 09:58:05,981 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (pool-7-thread-5) [405bc4cf] START, CreateImageVDSCommand( CreateImageVDSCommandParameters:{runAsync='true', storagePoolId='00000001-0001-0001-0001-0000000000ec', ignoreFailoverLimit='false', storageDomainId='556abaa8-0fcc-4042-963b-f27db5e03837', imageGroupId='e82eb204-0037-46df-b04e-549981de05fa', imageSizeInBytes='42949672960', volumeFormat='COW', newImageId='41801e6d-81ef-4243-a829-d14eafa9bbfd', newImageDescription='{"DiskAlias":"aaa","DiskDescription":""}', imageInitialSizeInBytes='0'}), log id: 62c2d8ef
2016-08-29 09:58:05,982 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (pool-7-thread-5) [405bc4cf] -- executeIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUID
2016-08-29 09:58:06,343 INFO  [org.ovirt.engine.core.bll.storage.disk.image.UploadDiskImageCommand] (DefaultQuartzScheduler5) [114b51be] Waiting for disk to be added for image transfer command '58473169-c5b9-4c67-84f2-69b54226f84c'
2016-08-29 09:58:07,181 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (pool-7-thread-5) [405bc4cf] FINISH, CreateImageVDSCommand, return: 41801e6d-81ef-4243-a829-d14eafa9bbfd, log id: 62c2d8ef
2016-08-29 09:58:07,182 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (pool-7-thread-5) [405bc4cf] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command '42e2f54d-4d20-4b9e-ba03-f08612221252'
2016-08-29 09:58:07,182 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (pool-7-thread-5) [405bc4cf] CommandMultiAsyncTasks::attachTask: Attaching task 'ed5b4d8f-1bea-479a-9c73-59ce4667dbdb' to command '42e2f54d-4d20-4b9e-ba03-f08612221252'.
2016-08-29 09:58:07,242 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (pool-7-thread-5) [405bc4cf] Adding task 'ed5b4d8f-1bea-479a-9c73-59ce4667dbdb' (Parent Command 'AddImageFromScratch', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling hasn't started yet..
2016-08-29 09:58:07,354 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (pool-7-thread-5) [405bc4cf] Correlation ID: 246dd4a8, Call Stack: null, Custom Event ID: -1, Message: Add-Disk operation of 'aaa' was initiated by the system.
2016-08-29 09:58:07,354 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (pool-7-thread-5) [405bc4cf] BaseAsyncTask::startPollingTask: Starting to poll task 'ed5b4d8f-1bea-479a-9c73-59ce4667dbdb'.
2016-08-29 09:58:08,356 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler1) [405bc4cf] Command 'AddDisk' (id: '56a18eb9-bb48-4e54-820a-4db841a2515e') waiting on child command id: '42e2f54d-4d20-4b9e-ba03-f08612221252' type:'AddImageFromScratch' to complete
2016-08-29 09:58:08,363 INFO  [org.ovirt.engine.core.bll.storage.disk.image.UploadDiskImageCommand] (DefaultQuartzScheduler1) [114b51be] Waiting for disk to be added for image transfer command '58473169-c5b9-4c67-84f2-69b54226f84c'
2016-08-29 09:58:10,565 INFO  [org.ovirt.engine.core.bll.storage.disk.image.UploadImageStatusCommand] (default task-61) [1a858227] Running command: UploadImageStatusCommand internal: false. Entities affected :  ID: aaa00000-0000-0000-0000-123456789aaa Type: SystemAction group CREATE_DISK with role type USER
2016-08-29 09:58:11,350 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler7) [54aca193] Polling and updating Async Tasks: 2 tasks, 1 tasks to poll now
2016-08-29 09:58:12,359 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler7) [54aca193] SPMAsyncTask::PollTask: Polling task 'ed5b4d8f-1bea-479a-9c73-59ce4667dbdb' (Parent Command 'AddImageFromScratch', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'success'.
2016-08-29 09:58:12,360 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler7) [54aca193] BaseAsyncTask::onTaskEndSuccess: Task 'ed5b4d8f-1bea-479a-9c73-59ce4667dbdb' (Parent Command 'AddImageFromScratch', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended successfully.
2016-08-29 09:58:12,362 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler7) [54aca193] CommandAsyncTask::endActionIfNecessary: All tasks of command '42e2f54d-4d20-4b9e-ba03-f08612221252' has ended -> executing 'endAction'
2016-08-29 09:58:12,362 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler7) [54aca193] CommandAsyncTask::endAction: Ending action for '1' tasks (command ID: '42e2f54d-4d20-4b9e-ba03-f08612221252'): calling endAction '.
2016-08-29 09:58:12,362 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-43) [54aca193] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction 'AddImageFromScratch', executionIndex: '0'
2016-08-29 09:58:12,376 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler2) [405bc4cf] Command 'AddDisk' id: '56a18eb9-bb48-4e54-820a-4db841a2515e' child commands '[42e2f54d-4d20-4b9e-ba03-f08612221252]' executions were completed, status 'SUCCEEDED'
2016-08-29 09:58:12,376 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler2) [405bc4cf] Command 'AddDisk' id: '56a18eb9-bb48-4e54-820a-4db841a2515e' Updating status to 'SUCCEEDED', The command end method logic will be executed by one of its parent commands.
2016-08-29 09:58:12,386 INFO  [org.ovirt.engine.core.bll.storage.disk.image.AddImageFromScratchCommand] (org.ovirt.thread.pool-8-thread-43) [405bc4cf] Command [id=42e2f54d-4d20-4b9e-ba03-f08612221252]: Updating status to 'SUCCEEDED', The command end method logic will be executed by one of its parent commands.
2016-08-29 09:58:12,387 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-43) [405bc4cf] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'AddImageFromScratch' completed, handling the result.
2016-08-29 09:58:12,387 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-43) [405bc4cf] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'AddImageFromScratch' succeeded, clearing tasks.
2016-08-29 09:58:12,387 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-43) [405bc4cf] SPMAsyncTask::ClearAsyncTask: Attempting to clear task 'ed5b4d8f-1bea-479a-9c73-59ce4667dbdb'
2016-08-29 09:58:12,388 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-43) [405bc4cf] START, SPMClearTaskVDSCommand( SPMTaskGuidBaseVDSCommandParameters:{runAsync='true', storagePoolId='00000001-0001-0001-0001-0000000000ec', ignoreFailoverLimit='false', taskId='ed5b4d8f-1bea-479a-9c73-59ce4667dbdb'}), log id: 6ab9e400
2016-08-29 09:58:12,389 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-43) [405bc4cf] START, HSMClearTaskVDSCommand(HostName = hosted_engine_1, HSMTaskGuidBaseVDSCommandParameters:{runAsync='true', hostId='0d6cfc43-99bb-468e-92d8-f615ef3362ae', taskId='ed5b4d8f-1bea-479a-9c73-59ce4667dbdb'}), log id: 617d1278
2016-08-29 09:58:12,426 INFO  [org.ovirt.engine.core.bll.storage.disk.image.UploadDiskImageCommand] (DefaultQuartzScheduler2) [114b51be] Successfully added disk 'aaa' (id 'e82eb204-0037-46df-b04e-549981de05fa') for image transfer command '58473169-c5b9-4c67-84f2-69b54226f84c'
2016-08-29 09:58:12,476 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.PrepareImageVDSCommand] (DefaultQuartzScheduler2) [114b51be] START, PrepareImageVDSCommand(HostName = hosted_engine_1, PrepareImageVDSCommandParameters:{runAsync='true', hostId='0d6cfc43-99bb-468e-92d8-f615ef3362ae'}), log id: 1e0d4216
2016-08-29 09:58:12,476 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-43) [405bc4cf] FINISH, HSMClearTaskVDSCommand, log id: 617d1278
2016-08-29 09:58:12,476 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-43) [405bc4cf] FINISH, SPMClearTaskVDSCommand, log id: 6ab9e400
2016-08-29 09:58:12,490 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-43) [405bc4cf] BaseAsyncTask::removeTaskFromDB: Removed task 'ed5b4d8f-1bea-479a-9c73-59ce4667dbdb' from DataBase
2016-08-29 09:58:12,490 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-43) [405bc4cf] CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity '42e2f54d-4d20-4b9e-ba03-f08612221252'
2016-08-29 09:58:13,513 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.PrepareImageVDSCommand] (DefaultQuartzScheduler2) [114b51be] FINISH, PrepareImageVDSCommand, return: PrepareImageReturnForXmlRpc:{status='StatusForXmlRpc [code=0, message=Done]'}, log id: 1e0d4216
2016-08-29 09:58:13,516 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeLegalityVDSCommand] (DefaultQuartzScheduler2) [114b51be] START, SetVolumeLegalityVDSCommand( SetVolumeLegalityVDSCommandParameters:{runAsync='true', storagePoolId='00000001-0001-0001-0001-0000000000ec', ignoreFailoverLimit='false', storageDomainId='556abaa8-0fcc-4042-963b-f27db5e03837', imageGroupId='e82eb204-0037-46df-b04e-549981de05fa', imageId='41801e6d-81ef-4243-a829-d14eafa9bbfd'}), log id: 12b863d7
2016-08-29 09:58:14,587 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeLegalityVDSCommand] (DefaultQuartzScheduler2) [114b51be] FINISH, SetVolumeLegalityVDSCommand, log id: 12b863d7
2016-08-29 09:58:14,588 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.AddImageTicketVDSCommand] (DefaultQuartzScheduler2) [114b51be] START, AddImageTicketVDSCommand(HostName = hosted_engine_1, AddImageTicketVDSCommandParameters:{runAsync='true', hostId='0d6cfc43-99bb-468e-92d8-f615ef3362ae', ticketId='3fa3eace-bee7-4156-8451-b22604c7e0e8', timeout='300', operations='[write]', size='1626800128', url='file:///rhev/data-center/00000001-0001-0001-0001-0000000000ec/556abaa8-0fcc-4042-963b-f27db5e03837/images/e82eb204-0037-46df-b04e-549981de05fa/41801e6d-81ef-4243-a829-d14eafa9bbfd'}), log id: 5a68fb59
2016-08-29 09:58:14,606 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.AddImageTicketVDSCommand] (DefaultQuartzScheduler2) [114b51be] FINISH, AddImageTicketVDSCommand, return: StatusOnlyReturnForXmlRpc [status=StatusForXmlRpc [code=0, message=Done]], log id: 5a68fb59
2016-08-29 09:58:14,606 INFO  [org.ovirt.engine.core.bll.storage.disk.image.UploadDiskImageCommand] (DefaultQuartzScheduler2) [114b51be] Started transfer session with ticket id 3fa3eace-bee7-4156-8451-b22604c7e0e8, timeout 300 seconds
2016-08-29 09:58:14,635 INFO  [org.ovirt.engine.core.bll.storage.disk.image.UploadImageCommand] (DefaultQuartzScheduler2) [114b51be] Updating image upload 58473169-c5b9-4c67-84f2-69b54226f84c (image e82eb204-0037-46df-b04e-549981de05fa) phase to Transferring (message: 'Initiating new upload')
2016-08-29 09:58:14,646 INFO  [org.ovirt.engine.core.bll.storage.disk.image.UploadDiskImageCommand] (DefaultQuartzScheduler2) [114b51be] Returning from proceedCommandExecution after starting transfer session for image transfer command '58473169-c5b9-4c67-84f2-69b54226f84c'
2016-08-29 09:58:15,467 INFO  [org.ovirt.engine.core.bll.storage.disk.image.UploadImageStatusCommand] (default task-11) [7a02198] Running command: UploadImageStatusCommand internal: false. Entities affected :  ID: aaa00000-0000-0000-0000-123456789aaa Type: SystemAction group CREATE_DISK with role type USER
2016-08-29 09:58:19,506 INFO  [org.ovirt.engine.core.bll.storage.disk.image.UploadImageStatusCommand] (default task-19) [7aadf44d] Running command: UploadImageStatusCommand internal: false. Entities affected :  ID: aaa00000-0000-0000-0000-123456789aaa Type: SystemAction group CREATE_DISK with role type USER
2016-08-29 09:58:25,032 INFO  [org.ovirt.engine.core.bll.storage.disk.image.UploadImageStatusCommand] (default task-28) [1a0a40ca] Running command: UploadImageStatusCommand internal: false. Entities affected :  ID: aaa00000-0000-0000-0000-123456789aaa Type: SystemAction group CREATE_DISK with role type USER
2016-08-29 09:58:27,943 INFO  [org.ovirt.engine.core.bll.storage.disk.image.UploadImageStatusCommand] (default task-38) [5d6aeec5] Running command: UploadImageStatusCommand internal: false. Entities affected :  ID: aaa00000-0000-0000-0000-123456789aaa Type: SystemAction group CREATE_DISK with role type USER
2016-08-29 09:58:28,580 INFO  [org.ovirt.engine.core.bll.storage.disk.image.UploadImageStatusCommand] (default task-39) [5b03fd03] Running command: UploadImageStatusCommand internal: false. Entities affected :  ID: aaa00000-0000-0000-0000-123456789aaa Type: SystemAction group CREATE_DISK with role type USER
2016-08-29 09:58:28,582 INFO  [org.ovirt.engine.core.bll.storage.disk.image.UploadImageCommand] (default task-39) [5b03fd03] Updating image upload 58473169-c5b9-4c67-84f2-69b54226f84c (image e82eb204-0037-46df-b04e-549981de05fa) phase to Paused by System (message: 'Sent 0MB')
2016-08-29 09:58:29,721 INFO  [org.ovirt.engine.core.bll.storage.disk.image.UploadDiskImageCommand] (DefaultQuartzScheduler4) [114b51be] Upload to disk 'aaa' (id 'e82eb204-0037-46df-b04e-549981de05fa') was paused by system
2016-08-29 09:58:29,736 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.RemoveImageTicketVDSCommand] (DefaultQuartzScheduler4) [114b51be] START, RemoveImageTicketVDSCommand(HostName = hosted_engine_1, RemoveImageTicketVDSCommandParameters:{runAsync='true', hostId='0d6cfc43-99bb-468e-92d8-f615ef3362ae', ticketId='3fa3eace-bee7-4156-8451-b22604c7e0e8', timeout='null'}), log id: 4af2721c
2016-08-29 09:58:30,744 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.RemoveImageTicketVDSCommand] (DefaultQuartzScheduler4) [114b51be] FINISH, RemoveImageTicketVDSCommand, return: StatusOnlyReturnForXmlRpc [status=StatusForXmlRpc [code=0, message=Done]], log id: 4af2721c
2016-08-29 09:58:30,744 INFO  [org.ovirt.engine.core.bll.storage.disk.image.UploadDiskImageCommand] (DefaultQuartzScheduler4) [114b51be] Successfully stopped image transfer session for ticket '3fa3eace-bee7-4156-8451-b22604c7e0e8'
2016-08-29 09:58:32,473 INFO  [org.ovirt.engine.core.bll.storage.disk.image.UploadImageStatusCommand] (default task-55) [74241814] Running command: UploadImageStatusCommand internal: false. Entities affected :  ID: aaa00000-0000-0000-0000-123456789aaa Type: SystemAction group CREATE_DISK with role type USER
and so on...

Comment 23 Radek Duda 2016-08-29 08:08:00 UTC
(In reply to Amit Aviram from comment #17)
> (In reply to Radek Duda from comment #15)
> > I tried to change values in the file
> > > - vim /etc/ovirt-imageio-proxy/ovirt-imageio-proxy.conf
> > > - :%s/imageio-proxy/reports/
> > 
> > then
> > # systemctl restart ovirt-imageio-proxy.service
> > and service is activated
> 
> At this point you are ready to upload your image.
> 
> > nevertheless if
> > #  /usr/bin/ovirt-imageio-proxy --stdout debug 
> > (MainThread) DEBUG root:Configuration value port = 54323
> > (MainThread) DEBUG root:Configuration value host = 
> > (MainThread) DEBUG root:Configuration value use_ssl = true
> > (MainThread) DEBUG root:Configuration value ssl_key_file =
> > /etc/pki/ovirt-engine/keys/reports.key.nopass
> > (MainThread) DEBUG root:Configuration value ssl_cert_file =
> > /etc/pki/ovirt-engine/certs/reports.cer
> > (MainThread) DEBUG root:Configuration value engine_cert_file =
> > /etc/pki/ovirt-engine/certs/engine.cer
> > (MainThread) DEBUG root:Configuration value engine_ca_cert_file =
> > /etc/pki/ovirt-engine/ca.pem
> > (MainThread) DEBUG root:Configuration value verify_certificate = true
> > (MainThread) INFO root:Server started, unable to notify systemd
> > 
> 
> Right, because the service runs and waits for requests. you will start see
> them when you'll start upload.
> 
> > 
> > If I run engine-setup, the values in file
> > /etc/ovirt-imageio-proxy/ovirt-imageio-proxy.conf are rewritten back.
> Assuming you don't need to setup over and over again, maybe this workaround
> is enough until you'll update your version.
> 
> Btw, you can also just copy reports.key.nopass and reports.cer and call it
> imageio-proxy.key.nopass and imageio-proxy.cer, and then running setup won't
> ruin your modified env. might be easiest.

I just update to newest rhev-m 4.0.3-0.1.el7ev without any ERROR message and with image-proxy.cer certificate in /etc/ovirt-imageio-proxy/ovirt-imageio-proxy.conf file. So it works ok for me now.

Comment 24 Aleksei Slaikovskii 2016-08-29 12:42:00 UTC
Hello! Just went thought steps to verify:

1. Installed ovirt-engine-4.0.1.1-0.1.el7ev.noarch
2. Changed system repos to 4.0.3-1
3. Upgraded ovirt-engine-setup-* and ovirt-engine-dwh-setup packages
4. engine-setup -> OK
5. yum update
6. engine-setup -> OK

So I guess it's ok, make it verified.


Note You need to log in before you can comment on or make changes to this bug.