Iscsi target mount from NAS slow on boot

I have a single iscsi target on Asustor NAS , but after adding it to fstab, F37 boot is 2 min slower, because the iscsi.service is reloaded twice during boot, and I don’t know why.

$ sudo iscsiadm -m discovery -t st -p 192.168.0.90
192.168.0.90:3260,1 iqn.2011-08.com.asustor:as5304t-8d33b5.target001
172.17.0.1:3260,1 iqn.2011-08.com.asustor:as5304t-8d33b5.target001

$ sudo blkid
/dev/sdc1: UUID="a8ba2edc-5c7c-41b3-bc78-6b8229dedb7d" BLOCK_SIZE="4096" TYPE="ext4" PARTLABEL="primary" PARTUUID="19732655-96b8-439c-9ff1-07928f2486ef"

$ sudo iscsiadm -m session -o show
tcp: [1] 192.168.0.90:3260,1 iqn.2011-08.com.asustor:as5304t-8d33b5.target001 (non-flash)

The slowest service is

$ systemd-analyze blame
2min 1.740s iscsi.service

# the slowest line is 
$ echo "$(< /var/log/boot.log)"
[  OK  ] Finished iscsi.service - Login and scanning of iSCSI devices.

$ systemd-analyze critical-chain
The time when unit became active or started is printed after the "@" character.
The time the unit took to start is printed after the "+" character.

graphical.target @2min 35.648s
└─multi-user.target @2min 35.648s
  └─plymouth-quit-wait.service @2min 14.928s +20.711s
    └─systemd-user-sessions.service @2min 14.891s +15ms
      └─remote-fs.target @2min 14.877s
        └─home-oglop-iscsi.mount @2min 14.846s +30ms
          └─remote-fs-pre.target @2min 14.828s
            └─iscsi.service @13.085s +2min 1.740s
              └─iscsid.service @13.201s +105ms
                └─network-online.target @13.073s
                  └─NetworkManager-wait-online.service @4.821s +8.250s
                    └─NetworkManager.service @4.738s +63ms
                      └─network-pre.target @4.720s
                        └─firewalld.service @3.911s +807ms
                          └─polkit.service @3.494s +388ms
                            └─basic.target @3.296s
                              └─dbus-broker.service @3.200s +91ms
                                └─dbus.socket @3.165s
                                  └─sysinit.target @3.100s
                                    └─systemd-resolved.service @2.581s +517ms
                                      └─systemd-tmpfiles-setup.service @2.326s +205ms
                                        └─local-fs.target @2.313s
                                          └─run-user-1000-doc.mount @2min 26.179s
                                            └─run-user-1000.mount @2min 15.287s
                                              └─local-fs-pre.target @1.792s
                                                └─lvm2-monitor.service @1.012s +773ms
                                                  └─dm-event.socket @980ms
                                                    └─system.slice
                                                      └─-.slice

/etc/systemd/system/remote-fs.target.wants/iscsi.service is the default one from F37 I did not change anything

[Unit]
Description=Login and scanning of iSCSI devices
Documentation=man:iscsiadm(8) man:iscsid(8)
DefaultDependencies=no
Before=remote-fs-pre.target
After=network.target network-online.target iscsid.service iscsiuio.service systemd-remount-fs.service
Wants=remote-fs-pre.target
ConditionDirectoryNotEmpty=/var/lib/iscsi/nodes

[Service]
Type=oneshot
RemainAfterExit=true
ExecStart=-/usr/sbin/iscsiadm -m node --loginall=automatic
ExecReload=-/usr/sbin/iscsiadm -m node --loginall=automatic
SuccessExitStatus=21

[Install]
WantedBy=remote-fs.target

iscsi.service log

$ sudo journalctl -u iscsi -b
Dec 27 00:33:48 t450s systemd[1]: Starting iscsi.service - Login and scanning of iSCSI devices...
Dec 27 00:35:51 t450s iscsiadm[1325]: iscsiadm: Could not login to [iface: default, target: iqn.2011-08.com.asustor:as5304t-8d33b5.target0>
Dec 27 00:35:51 t450s iscsiadm[1325]: iscsiadm: initiator reported error (8 - connection timed out)
Dec 27 00:35:51 t450s iscsiadm[1325]: iscsiadm: Could not log into all portals
Dec 27 00:35:51 t450s iscsiadm[1325]: Logging in to [iface: default, target: iqn.2011-08.com.asustor:as5304t-8d33b5.target001, portal: 192>
Dec 27 00:35:51 t450s iscsiadm[1325]: Logging in to [iface: default, target: iqn.2011-08.com.asustor:as5304t-8d33b5.target001, portal: 172>
Dec 27 00:35:51 t450s iscsiadm[1325]: Login to [iface: default, target: iqn.2011-08.com.asustor:as5304t-8d33b5.target001, portal: 192.168.>
Dec 27 00:35:51 t450s systemd[1]: Finished iscsi.service - Login and scanning of iSCSI devices.
Dec 27 00:35:51 t450s systemd[1]: Reloading iscsi.service - Login and scanning of iSCSI devices...
Dec 27 00:37:54 t450s iscsiadm[1529]: iscsiadm: Could not login to [iface: default, target: iqn.2011-08.com.asustor:as5304t-8d33b5.target0>
Dec 27 00:37:54 t450s iscsiadm[1529]: iscsiadm: initiator reported error (8 - connection timed out)
Dec 27 00:37:54 t450s iscsiadm[1529]: iscsiadm: Could not log into all portals
Dec 27 00:37:54 t450s iscsiadm[1529]: Logging in to [iface: default, target: iqn.2011-08.com.asustor:as5304t-8d33b5.target001, portal: 172>
Dec 27 00:37:54 t450s systemd[1]: Reloaded iscsi.service - Login and scanning of iSCSI devices.

I can see from above log that

Dec 27 00:35:51 t450s systemd[1]: Finished iscsi.service - Login and scanning of iSCSI devices.
Dec 27 00:35:51 t450s systemd[1]: Reloading iscsi.service - Login and scanning of iSCSI devices...

it finishes loading the service, then it started reloading the service, and then it took 2min to finish loading it. not sure why it wants to reload again.

After booting the mount works fine, it is just that the boot time is slow, if I comment out the line fstab, the boot is fast again, but I want it to be auto mounted on boot.

If I manually restart the service, it also takes 2 min

$ sudo systemctl restart iscsi.service

$ sudo journalctl -u iscsi
Dec 27 12:23:07 t450s systemd[1]: iscsi.service: Deactivated successfully.
Dec 27 12:23:07 t450s systemd[1]: Stopped iscsi.service - Login and scanning of iSCSI devices.
Dec 27 12:23:07 t450s systemd[1]: Stopping iscsi.service - Login and scanning of iSCSI devices...
Dec 27 12:23:07 t450s systemd[1]: Starting iscsi.service - Login and scanning of iSCSI devices...
Dec 27 12:25:09 t450s iscsiadm[6021]: iscsiadm: Could not login to [iface: default, target: iqn.2011-08.com.asustor:as5304t-8d33b5.target>
Dec 27 12:25:09 t450s iscsiadm[6021]: iscsiadm: initiator reported error (8 - connection timed out)
Dec 27 12:25:09 t450s iscsiadm[6021]: iscsiadm: Could not log into all portals
Dec 27 12:25:09 t450s iscsiadm[6021]: Logging in to [iface: default, target: iqn.2011-08.com.asustor:as5304t-8d33b5.target001, portal: 17>
Dec 27 12:25:09 t450s systemd[1]: Finished iscsi.service - Login and scanning of iSCSI devices.

There might be an answer here but I can not see the hidden solution. Scanning of iscsi device delays two minutes during server boot - Red Hat Customer Portal

Finally I found a dirty hack

  1. use this in /etc/fstab
UUID=a8ba2edc-5c7c-41b3-bc78-6b8229dedb7d /home/oglop/iscsi ext4 defaults,_netdev,noauto,x-systemd.automount 0 0
  1. modified iscsi.service Type= from oneshot to forking
sudo systemctl edit --full iscsi

This is the most confusing part, according to systemd.service doc, oneshot is exactly the type we need here, but forking removes the delay and still show correct service status after booting.

my full iscsi.service

[Unit]
Description=Login and scanning of iSCSI devices
Documentation=man:iscsiadm(8) man:iscsid(8)
DefaultDependencies=no
Before=remote-fs-pre.target
After=network.target network-online.target iscsid.service iscsiuio.service systemd-remount-fs.service
Wants=remote-fs-pre.target
ConditionDirectoryNotEmpty=/var/lib/iscsi/nodes

[Service]
#Type=oneshot
Type=forking
RemainAfterExit=true
ExecStart=-/usr/sbin/iscsiadm -m node --loginall=automatic
ExecReload=-/usr/sbin/iscsiadm -m node --loginall=automatic
SuccessExitStatus=21

[Install]
WantedBy=remote-fs.target

update: the hack worked for a few hours, then it started to cause default 90s delay.

I added --debug=8 to iscsi.service, here is the full log when using Type=oneshot

I wonder if adding nofail to the mount options would have fixed it? I think that flag is supposed to cause the mount to happen asynchronously during boot.

I suddenly realized that it is because it is trying to login to the second target I had on NAS, not sure how that got created I have only one lun there.

After

sudo iscsiadm --m node -T iqn.2011-08.com.asustor:as5304t-8d33b5.target001 -p 172.17.0.1:3260 -o delete

and reboot, everything is awesome now, no delays

1 Like