On pondělí 27. dubna 2020 16:47:56 CEST Nir Soffer wrote:
> On Mon, Apr 27, 2020 at 5:37 PM Sandro Bonazzola <sbonazzo@redhat.com>
wrote:
> > Il giorno lun 27 apr 2020 alle ore 16:28 Nir Soffer <nsoffer@redhat.com>
ha scritto:
> >> On Mon, Apr 27, 2020 at 5:22 PM Vojtech Juranek <vjuranek@redhat.com>
wrote:
> >> > On pondělí 27. dubna 2020 16:10:11 CEST Nir Soffer wrote:
> >> > > On Mon, Apr 27, 2020 at 5:01 PM Liran Rotenberg <lrotenbe@redhat.com>
wrote:
> >> > > > On Mon, Apr 27, 2020 at 4:58 PM Sandro Bonazzola
> >> > > > <sbonazzo@redhat.com>
> >> > > >
> >> > > > wrote:
> >> > > >> Il giorno lun 27 apr 2020 alle ore 15:52 Nir Soffer
> >> > > >> <nsoffer@redhat.com>
> >> > > >>
> >> > > >> ha scritto:
> >> > > >>> On Mon, Apr 27, 2020 at 4:42 PM Sandro Bonazzola
> >> > > >>> <sbonazzo@redhat.com>
> >> > > >>>
> >> > > >>> wrote:
> >> > > >>>> Failing job is
> >> > > >>>> https://jenkins.ovirt.org/job/ovirt-system-tests_manual/6794/
> >> > > >>>>
> >> > > >>>> Here's the relevant log in engine-setup:
> >> > > >>>>
> >> > > >>>>
> >> > > >>>> 2020-04-27 09:25:35,457-0400 DEBUG
> >> > > >>>> otopi.plugins.otopi.services.systemd
> >> > > >>>> plugin.executeRaw:813 execute: ('/usr/bin/systemctl', 'stop',
> >> > > >>>> 'ovirt-imageio.service'), executable='None', cwd='None',
> >> > > >>>> env=None
> >> > > >>>> 2020-04-27 09:25:35,652-0400 DEBUG
> >> > > >>>> otopi.plugins.otopi.services.systemd plugin.executeRaw:863
> >> > > >>>> execute-result: ('/usr/bin/systemctl', 'stop',
> >> > > >>>> 'ovirt-imageio.service'), rc=0 2020-04-27 09:25:35,653-0400
> >> > > >>>> DEBUG
> >> > > >>>> otopi.plugins.otopi.services.systemd plugin.execute:921
> >> > > >>>> execute-output: ('/usr/bin/systemctl', 'stop',
> >> > > >>>> 'ovirt-imageio.service') stdout:
> >> > > >>>>
> >> > > >>>>
> >> > > >>>> 2020-04-27 09:25:35,653-0400 DEBUG
> >> > > >>>> otopi.plugins.otopi.services.systemd
> >> > > >>>> plugin.execute:926 execute-output: ('/usr/bin/systemctl',
> >> > > >>>> 'stop',
> >> > > >>>> 'ovirt-imageio.service') stderr:
> >> > > >>>>
> >> > > >>>>
> >> > > >>>> 2020-04-27 09:25:35,653-0400 DEBUG
> >> > > >>>> otopi.plugins.otopi.services.systemd
> >> > > >>>> systemd.state:170 starting service ovirt-imageio 2020-04-27
> >> > > >>>> 09:25:35,654-0400 DEBUG otopi.plugins.otopi.services.systemd
> >> > > >>>> plugin.executeRaw:813 execute: ('/usr/bin/systemctl', 'start',
> >> > > >>>> 'ovirt-imageio.service'), executable='None', cwd='None',
> >> > > >>>> env=None
> >> > > >>>> 2020-04-27 09:25:36,631-0400 DEBUG
> >> > > >>>> otopi.plugins.otopi.services.systemd plugin.executeRaw:863
> >> > > >>>> execute-result: ('/usr/bin/systemctl', 'start',
> >> > > >>>> 'ovirt-imageio.service'), rc=1 2020-04-27 09:25:36,632-0400
> >> > > >>>> DEBUG
> >> > > >>>> otopi.plugins.otopi.services.systemd plugin.execute:921
> >> > > >>>> execute-output: ('/usr/bin/systemctl', 'start',
> >> > > >>>> 'ovirt-imageio.service') stdout:
> >> > > >>>>
> >> > > >>>>
> >> > > >>>> 2020-04-27 09:25:36,632-0400 DEBUG
> >> > > >>>> otopi.plugins.otopi.services.systemd
> >> > > >>>> plugin.execute:926 execute-output: ('/usr/bin/systemctl',
> >> > > >>>> 'start',
> >> > > >>>> 'ovirt-imageio.service') stderr: Job for ovirt-imageio.service
> >> > > >>>> failed
> >> > > >>>> because the control process exited with error code. See
> >> > > >>>> "systemctl
> >> > > >>>> status ovirt-imageio.service" and "journalctl -xe" for details.
> >> > > >>>>
> >> > > >>>> 2020-04-27 09:25:36,633-0400 DEBUG otopi.context
> >> > > >>>> context._executeMethod:145 method exception>>>>
> >> > > >>>>
> >> > > >>>> Traceback (most recent call last):
> >> > > >>>>   File "/usr/lib/python3.6/site-packages/otopi/context.py", line
> >> > > >>>>   132,
> >> > > >>>>   in _executeMethod>>>>
> >> > > >>>>   
> >> > > >>>>     method['method']()
> >> > > >>>>   
> >> > > >>>>   File
> >> > > >>>>   "/usr/share/ovirt-engine/setup/bin/../plugins/ovirt-engine-set
> >> > > >>>>   up/ovi
> >> > > >>>>   rt_imageio/config.py", line 190, in
> >> > > >>>>   _closeup_resatrt_service>>>>
> >> > > >>>>   
> >> > > >>>>     state=state,
> >> > > >>>>   
> >> > > >>>>   File "/usr/share/otopi/plugins/otopi/services/systemd.py",
> >> > > >>>>   line 181,
> >> > > >>>>   in state>>>>
> >> > > >>>>   
> >> > > >>>>     service=name,
> >> > > >>>>
> >> > > >>>> RuntimeError: Failed to start service 'ovirt-imageio'
> >> > > >>>> 2020-04-27 09:25:36,636-0400 ERROR otopi.context
> >> > > >>>> context._executeMethod:154 Failed to execute stage 'Closing up':
> >> > > >>>> Failed to start service 'ovirt-imageio'>>>
> >> > > >>>
> >> > > >>> Looking at the logs at:
> >> > > >>>
> >> > > >>> https://jenkins.ovirt.org/job/ovirt-system-tests_manual/6794/arti
> >> > > >>> fact/ex
> >> > > >>> ported-artifacts/test_logs/basic-suite-master/post-001_initialize
> >> > > >>> _engine
> >> > > >>> _pytest.py/lago-basic-suite-master-engine/_var_log/ovirt-imageio/
> >> > > >>> daemon.
> >> > > >>> log
> >> > > >>>
> >> > > >>> 2020-04-27 09:25:39,887 INFO    (MainThread) [server] Starting
> >> > > >>> (pid=17137, version=2.0.5) 2020-04-27 09:25:39,944 ERROR 
> >> > > >>> (MainThread)
> >> > > >>> [server] Server failed>>>
> >> > > >>>
> >> > > >>> Traceback (most recent call last):
> >> > > >>>   File
> >> > > >>>   "/usr/lib64/python3.6/site-packages/ovirt_imageio/server.py",
> >> > > >>>   line 37, in main>>>
> >> > > >>>   
> >> > > >>>     server = Server(cfg)
> >> > > >>>   
> >> > > >>>   File
> >> > > >>>   "/usr/lib64/python3.6/site-packages/ovirt_imageio/server.py",
> >> > > >>>   line 76, in __init__>>>
> >> > > >>>   
> >> > > >>>     self.remote_service = services.RemoteService(self.config,
> >> > > >>>     self.auth)
> >> > > >>>   
> >> > > >>>   File
> >> > > >>>   "/usr/lib64/python3.6/site-packages/ovirt_imageio/services.py"
> >> > > >>>   ,
> >> > > >>>   line 80, in __init__>>>
> >> > > >>>   
> >> > > >>>     self._secure_server()
> >> > > >>>   
> >> > > >>>   File
> >> > > >>>   "/usr/lib64/python3.6/site-packages/ovirt_imageio/services.py"
> >> > > >>>   ,
> >> > > >>>   line 95, in _secure_server>>>
> >> > > >>>   
> >> > > >>>     raise errors.TlsConfigurationError(*required_config)
> >> > > >>>
> >> > > >>> ovirt_imageio.errors.TlsConfigurationError: TLS enabled (see
> >> > > >>> [tls]
> >> > > >>> section in daemon.conf), but not configured: ca_file = ,
> >> > > >>> cert_file = ,
> >> > > >>> key_file =
> >> > > >>>
> >> > > >>> This means engine-setup did not create correct configuration
> >> > > >>> file.
> >> > > >>>
> >> > > >>> Looking in
> >> > > >>> https://jenkins.ovirt.org/job/ovirt-system-tests_manual/6794/
> >> > > >>> I don't see /etc/ovirt-imageio directory, maybe the collections
> >> > > >>> scripts
> >> > > >>> need update?
> >> > > >>>
> >> > > >>> This works in real setup, so I guess this is another OST
> >> > > >>> environment
> >> > > >>> issue.
> >> > > >>
> >> > > >> looking at dnf logs:
> >> > > >> https://jenkins.ovirt.org/job/ovirt-system-tests_manual/6794/artif
> >> > > >> act/exp
> >> > > >> orted-artifacts/test_logs/basic-suite-master/post-001_initialize_e
> >> > > >> ngine_p
> >> > > >> ytest.py/lago-basic-suite-master-engine/_var_log/dnf.rpm.log
> >> > > >>
> >> > > >> 2020-04-27T13:16:13Z SUBDEBUG Installed:
> >> > > >> ovirt-imageio-common-2.0.5-0.202004260154.gitaf86468.el8.x86_64
> >> > > >> 2020-04-27T13:16:13Z SUBDEBUG Installed:
> >> > > >> ovirt-imageio-common-2.0.5-0.202004260154.gitaf86468.el8.x86_64
> >> > > >> 2020-04-27T13:16:13Z SUBDEBUG Installed:
> >> > > >> ovirt-imageio-daemon-2.0.5-0.202004260154.gitaf86468.el8.x86_64
> >> > > >> 2020-04-27T13:16:14Z SUBDEBUG Installed:
> >> > > >> ovirt-imageio-daemon-2.0.5-0.202004260154.gitaf86468.el8.x86_64
> >> > > >> 2020-04-27T13:16:14Z INFO warning: group Development/Debug does
> >> > > >> not
> >> > > >> exist - using root
> >> > > >>
> >> > > >> seems like it's getting a recent enough version. What about above
> >> > > >> warning?
> >> > > >
> >> > > > I had this problem in my local environment. I was running
> >> > > > engine-setup
> >> > > > with an unprivileged user.
> >> > >
> >> > > For make install-dev?
> >> > >
> >> > > I think this was fixed here:
> >> > >
> >> > > commit 81a5e757fd8768ace825140ca7dc701cc2e011ce
> >> > > Author: Vojtech Juranek <vjuranek@redhat.com>
> >> > > Date:   Thu Apr 23 11:44:41 2020 +0200
> >> > >
> >> > >     spec: allow imageio config in dev env
> >> > >     
> >> > >     Add $PREFIX into imageio config directory to allow imageio
> >> > >     configuration
> >> > >
> >> > > in development environment when config files are installed into a
> >> > > specified
> >> > > directory.
> >> > >
> >> > >     Currently it fails with:
> >> > >         [Errno 13] Permission denied: '/etc/ovirt-imageio'
> >> > >     
> >> > >     Change-Id: I9e13bba0e97f681b0b07d5a135be76113e391ddc
> >> > >     Signed-off-by: Vojtech Juranek <vjuranek@redhat.com>
> >> > >
> >> > > Maybe this OST runs old engine without this fix?
> >> >
> >> > OST runs in install-dev environment? IIRC not.
> >> >
> >> > Looking into the logs, imageio wasn't properly configured, it seems
there's no certificate configuration:
> >> >     ovirt_imageio.errors.TlsConfigurationError: TLS enabled (see [tls]
> >> >     section in daemon.conf), but not configured: ca_file = , cert_file
> >> >     = , key_file =>> >
> >> > (from
> >> > https://jenkins.ovirt.org/job/ovirt-system-tests_manual/6794/artifact/
> >> > exported-artifacts/test_logs/basic-suite-master/post-001_initialize_eng
> >> > ine_pytest.py/lago-basic-suite-master-engine/_var_log/ovirt-imageio/dae
> >> > mon.log)
> >> >
> >> > and as Nir wrote, /etc/ovirt-imageio is not archived
> >> >
> >> > looking into otopi log
> >> > (https://jenkins.ovirt.org/job/ovirt-system-tests_manual/6794/artifact
> >> > /exported-artifacts/test_logs/basic-suite-master/post-001_initialize_en
> >> > gine_pytest.py/lago-basic-suite-master-engine/_var_log/ovirt-engine/set
> >> > up/ovirt-engine-setup-20200427091928-9e7d0z.log) it looks like the
> >> > config ws installed into /usr/etc/ovirt-imageio instead of into
> >> > /usr/etc>>
> >> Maybe PREFIX was /usr when generating the rpms?
> >>
> >> This is the trouble with code that does not have automated tests. This
> >> means endless
> >> time spent on manual debugging.
> >>
> >> (so far no idea why, also I guess we need to throw clear exception if
> >
> >> the config file is not found):
> > Looking at Makefile:
> > IMAGEIO_SYSCONF_DIR=$(PREFIX)/etc/ovirt-imageio
> >
> > and this make sense to resolve to /usr/etc/ovirt-imageio.
> >
> > should have been:
> > IMAGEIO_SYSCONF_DIR=$(SYSCONF_DIR)/ovirt-imageio
> >
> > In spec file:
> > PREFIX=%{_prefix}
> > and rpm resolves:
> > $ rpm --eval "%{_prefix}"
> > /usr
> >
> > so this couldn't have worked before at all.
>
> Looks like the patch adding $PREFIX was not tested with real setup,
> only with development setup.

yes, and actually I haven't finished testing it even in dev setup yet

> Vojta, do you want to test a fix?

I'll, but need to look more into it, replacing $(PREFIX) with $(SYSCONF_DIR)
doesn't seem to work as SYSCONF_DIR=$(PREFIX)/etc (see https://github.com/
oVirt/ovirt-engine/blob/master/Makefile#L41), so we will end up again with /
usr/etc. We will probably have to do it as VMCONSOLE_* variable - hardcode
config file and define new just install-dev environment (and do the proper
testing before merge)