[ovirt-devel] Re: engine-setup failing on restarting ovirt-imageio

On Mon, Apr 27, 2020 at 5:37 PM Sandro Bonazzola <sbonazzo(a)redhat.com&gt;

> Il giorno lun 27 apr 2020 alle ore 16:28 Nir Soffer <nsoffer(a)redhat.com&gt;

>> On Mon, Apr 27, 2020 at 5:22 PM Vojtech Juranek <vjuranek(a)redhat.com&gt;

>> > 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(a)redhat.com&gt;

>> > > > On Mon, Apr 27, 2020 at 4:58 PM Sandro Bonazzola >> > > > <sbonazzo(a)redhat.com&gt; >> > > > >> > > > wrote: >> > > >> Il giorno lun 27 apr 2020 alle ore 15:52 Nir Soffer >> > > >> <nsoffer(a)redhat.com&gt; >> > > >> >> > > >> ha scritto: >> > > >>> On Mon, Apr 27, 2020 at 4:42 PM Sandro Bonazzola >> > > >>> <sbonazzo(a)redhat.com&gt; >> > > >>> >> > > >>> 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(a)redhat.com&gt; >> > > 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(a)redhat.com&gt; >> > > >> > > 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

>> > 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.

Vojta, do you want to test a fix?