Package: src:cinder
Tags: patch

Problem:

The cinder-volume.service unit is _not_ ordered after the tgt.service unit,
and thus might fail to run 'tgtadm' commands because tgtd is not yet ready,
on service start up / boot:

    INFO cinder.service [-] Starting cinder-volume node (version 12.0.9)
    ...
    ERROR cinder.volume.manager [req-UUID - - - - -] Failed to
re-export volume, setting to ERROR.: ProcessExecutionError: Unexpected
error while running command.
    Command: sudo cinder-rootwrap /etc/cinder/rootwrap.conf tgtadm
--lld iscsi --op show --mode target
    Exit code: 107
    Stdout: u''
    Stderr: u'tgtadm: failed to send request hdr to tgt daemon,
Transport endpoint is not connected\n'


Approach:

It should be OK to order `cinder-volume.service` (generated from
`cinder-volume.init.in` template) with `After=tgt.service`,
as the `cinder-volume` package has a `Depends: tgt` dependency, and
actually restarts `tgt` on its install/remove scripts,
thus it is already strongly bound to `tgt` at the packaging level,
even if its runtime usage is optional (eg, other drivers).

# dpkg -s cinder-volume | grep Depends:
Depends: ..., tgt, ...


Real-world example:

1) Unit `ovs-vswitchd.service` took 2 minutes to start up.
2) That delayed `network.target` (`ovs-vswitchd.service` has
`Before=network.target`).
3) That delayed `tgt.service` too (it has `After=network.target`).

4) BUT that did _not_ delay `cinder-volume.service` (it does _not_
have `After=tgt.service`)
5) So it failed to talk to tgtd with tgtadm, and volume re-export failed.

    $ cat sos_commands/logs/journalctl_--no-pager_--catalog_--boot \
      | grep -E -B1 'Subject: Unit
(cinder-volume.service|tgt.service|ovs-vswitchd.service|network.target)'

    Aug 10 06:23:15 <HOST> systemd[1]: Started OpenStack Cinder Volume.
    -- Subject: Unit cinder-volume.service has finished start-up
    --
    <<< ERROR in cinder-volume.log >>>

    Aug 10 06:23:16 <HOST> systemd[1]: Starting Open vSwitch Forwarding Unit...
    -- Subject: Unit ovs-vswitchd.service has begun start-up
    --
    <<< DELAY of 2 minutes >>>

    Aug 10 06:25:17 <HOST> systemd[1]: Started Open vSwitch Forwarding Unit.
    -- Subject: Unit ovs-vswitchd.service has finished start-up
    --
    Aug 10 06:25:17 <HOST> systemd[1]: Reached target Network.
    -- Subject: Unit network.target has finished start-up
    --
    Aug 10 06:25:17 <HOST> systemd[1]: Starting (i)SCSI target daemon...
    -- Subject: Unit tgt.service has begun start-up
    --
    Aug 10 06:25:19 <HOST> systemd[1]: Started (i)SCSI target daemon.
    -- Subject: Unit tgt.service has finished start-up

    <<< NOW tgtd is running >>>

@ var/log/cinder/cinder-volume.log

     9901 2022-08-10 06:23:21.515 3939 INFO cinder.service [-]
Starting cinder-volume node (version 12.0.9)
    ...
     9932 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
[req-e67a852a-6cce-4073-a2de-d3487c85d586 - - - - -] Failed to
re-export volume, setting to ERROR.: ProcessExecutionError: Unexpected
error while running command.
     9933 Command: sudo cinder-rootwrap /etc/cinder/rootwrap.conf
tgtadm --lld iscsi --op show --mode target
     9934 Exit code: 107
     9935 Stdout: u''
     9936 Stderr: u'tgtadm: failed to send request hdr to tgt daemon,
Transport endpoint is not connected\n'
     9937 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
Traceback (most recent call last):
     9938 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
File "/usr/lib/python2.7/dist-packages/cinder/volume/manager.py", line
486, in init_host
     9939 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
self.driver.ensure_export(ctxt, volume)
     9940 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
File "/usr/lib/python2.7/dist-packages/cinder/volume/drivers/lvm.py",
line 826, in ensure_export
     9941 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
self.target_driver.ensure_export(context, volume, volume_path)
     9942 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
File "/usr/lib/python2.7/dist-packages/cinder/volume/targets/iscsi.py",
line 261, in ensure_export
     9943 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
old_name=None, **portals_config)
     9944 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
File "/usr/lib/python2.7/dist-packages/cinder/utils.py", line 818, in
_wrapper
     9945 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
return r.call(f, *args, **kwargs)
     9946 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
File "/usr/lib/python2.7/dist-packages/retrying.py", line 206, in call
     9947 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
return attempt.get(self._wrap_exception)
     9948 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
File "/usr/lib/python2.7/dist-packages/retrying.py", line 247, in get
     9949 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
six.reraise(self.value[0], self.value[1], self.value[2])
     9950 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
File "/usr/lib/python2.7/dist-packages/retrying.py", line 200, in call
     9951 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
attempt = Attempt(fn(*args, **kwargs), attempt_number, False)
     9952 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
File "/usr/lib/python2.7/dist-packages/cinder/volume/targets/tgt.py",
line 141, in create_iscsi_target
     9953 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
run_as_root=True)
     9954 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
File "/usr/lib/python2.7/dist-packages/cinder/utils.py", line 126, in
execute
     9955 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
return processutils.execute(*cmd, **kwargs)
     9956 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
File "/usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py",
line 424, in execute
     9957 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
cmd=sanitized_cmd)
     9958 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
ProcessExecutionError: Unexpected error while running command.
     9959 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
Command: sudo cinder-rootwrap /etc/cinder/rootwrap.conf tgtadm --lld
iscsi --op show --mode target
     9960 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
Exit code: 107
     9961 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager Stdout: u''
     9962 2022-08-10 06:23:23.398 3932 ERROR cinder.volume.manager
Stderr: u'tgtadm: failed to send request hdr to tgt daemon, Transport
endpoint is not connected\n'

Launchpad/Ubuntu bug: https://bugs.launchpad.net/bugs/1987663

cheers,

--
Mauricio Faria de Oliveira

  • Bug#1018084: "Failed to re-export volume, ... Mauricio Faria de Oliveira

Reply via email to