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.
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'
Real-world example:
1) Unit `ovs-vswitchd. service` took 2 minutes to start up. service` has `Before= network. target` ). network. target` ).
2) That delayed `network.target` (`ovs-vswitchd.
3) That delayed `tgt.service` too (it has `After=
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 \ volume. service| tgt.service| ovs-vswitchd. service| network. target) '
| grep -E -B1 'Subject: Unit (cinder-
Aug 10 06:23:15 <HOST> systemd[1]: Started OpenStack Cinder Volume. volume. service has finished start-up
-- Subject: Unit cinder-
--
<<< ERROR in cinder-volume.log >>>
Aug 10 06:23:16 <HOST> systemd[1]: Starting Open vSwitch Forwarding Unit... service has begun start-up
-- Subject: Unit ovs-vswitchd.
--
<<< DELAY of 2 minutes >>>
Aug 10 06:25:17 <HOST> systemd[1]: Started Open vSwitch Forwarding Unit. service has finished start-up
-- Subject: Unit ovs-vswitchd.
--
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) volume. manager [req-e67a852a- 6cce-4073- a2de-d3487c85d5 86 - - - - -] Failed to re-export volume, setting to ERROR.: ProcessExecutio nError: Unexpected error while running command. rootwrap. conf tgtadm --lld iscsi --op show --mode target volume. manager Traceback (most recent call last): volume. manager File "/usr/lib/ python2. 7/dist- packages/ cinder/ volume/ manager. py", line 486, in init_host volume. manager self.driver. ensure_ export( ctxt, volume) volume. manager File "/usr/lib/ python2. 7/dist- packages/ cinder/ volume/ drivers/ lvm.py" , line 826, in ensure_export volume. manager self.target_ driver. ensure_ export( context, volume, volume_path) volume. manager File "/usr/lib/ python2. 7/dist- packages/ cinder/ volume/ targets/ iscsi.py" , line 261, in ensure_export volume. manager old_name=None, **portals_config) volume. manager File "/usr/lib/ python2. 7/dist- packages/ cinder/ utils.py" , line 818, in _wrapper volume. manager return r.call(f, *args, **kwargs) volume. manager File "/usr/lib/ python2. 7/dist- packages/ retrying. py", line 206, in call volume. manager return attempt. get(self. _wrap_exception ) volume. manager File "/usr/lib/ python2. 7/dist- packages/ retrying. py", line 247, in get volume. manager six.reraise( self.value[ 0], self.value[1], self.value[2]) volume. manager File "/usr/lib/ python2. 7/dist- packages/ retrying. py", line 200, in call volume. manager attempt = Attempt(fn(*args, **kwargs), attempt_number, False) volume. manager File "/usr/lib/ python2. 7/dist- packages/ cinder/ volume/ targets/ tgt.py" , line 141, in create_iscsi_target volume. manager run_as_root=True) volume. manager File "/usr/lib/ python2. 7/dist- packages/ cinder/ utils.py" , line 126, in execute volume. manager return processutils. execute( *cmd, **kwargs) volume. manager File "/usr/lib/ python2. 7/dist- packages/ oslo_concurrenc y/processutils. py", line 424, in execute volume. manager cmd=sanitized_cmd) volume. manager ProcessExecutio nError: Unexpected error while running command. volume. manager Command: sudo cinder-rootwrap /etc/cinder/ rootwrap. conf tgtadm --lld iscsi --op show --mode target volume. manager Exit code: 107 volume. manager Stdout: u'' volume. manager Stderr: u'tgtadm: failed to send request hdr to tgt daemon, Transport endpoint is not connected\n'
...
9932 2022-08-10 06:23:23.398 3932 ERROR cinder.
9933 Command: sudo cinder-rootwrap /etc/cinder/
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.
9938 2022-08-10 06:23:23.398 3932 ERROR cinder.
9939 2022-08-10 06:23:23.398 3932 ERROR cinder.
9940 2022-08-10 06:23:23.398 3932 ERROR cinder.
9941 2022-08-10 06:23:23.398 3932 ERROR cinder.
9942 2022-08-10 06:23:23.398 3932 ERROR cinder.
9943 2022-08-10 06:23:23.398 3932 ERROR cinder.
9944 2022-08-10 06:23:23.398 3932 ERROR cinder.
9945 2022-08-10 06:23:23.398 3932 ERROR cinder.
9946 2022-08-10 06:23:23.398 3932 ERROR cinder.
9947 2022-08-10 06:23:23.398 3932 ERROR cinder.
9948 2022-08-10 06:23:23.398 3932 ERROR cinder.
9949 2022-08-10 06:23:23.398 3932 ERROR cinder.
9950 2022-08-10 06:23:23.398 3932 ERROR cinder.
9951 2022-08-10 06:23:23.398 3932 ERROR cinder.
9952 2022-08-10 06:23:23.398 3932 ERROR cinder.
9953 2022-08-10 06:23:23.398 3932 ERROR cinder.
9954 2022-08-10 06:23:23.398 3932 ERROR cinder.
9955 2022-08-10 06:23:23.398 3932 ERROR cinder.
9956 2022-08-10 06:23:23.398 3932 ERROR cinder.
9957 2022-08-10 06:23:23.398 3932 ERROR cinder.
9958 2022-08-10 06:23:23.398 3932 ERROR cinder.
9959 2022-08-10 06:23:23.398 3932 ERROR cinder.
9960 2022-08-10 06:23:23.398 3932 ERROR cinder.
9961 2022-08-10 06:23:23.398 3932 ERROR cinder.
9962 2022-08-10 06:23:23.398 3932 ERROR cinder.