On Wed, Feb 04, 2015 at 12:51:08PM -0800, The Lee-Man wrote:
> >
> > I'm wondering if it has something to do with the ExecStop command 
> > returning before iscsid actually terminates, although I'm not sure 
> > what's triggering the service restart. 
> >
> 
> I think you're onto the meat of the problem: the sequencing systemd does 
> between the "ExecStop=" and the command itself. 
> 
> The systemd.service(5) man page says about ExecStop:
> 
> "...After the commands configured in this option are run, all processes 
> remaining for a service are terminated according to the KillMode= setting 
> (see systemd.kill(5))."
> 
> So I'm thinking systemd does not like that this command actually stops the 
> service. But this only happens if the service is socket-activated, so it 
> must be the socket service that is restarting iscsid. If I stop 
> iscsid.socket before iscsid.service, this does not happen. But systemd 
> doesn't normally shut things down that way, since iscsid.service depends on 
> iscsid.socket.

OK, I ran this test script until it failed in the way you're seeing

---
  #!/bin/sh
  
  # make sure systemd is logging at debug level
  LOGLEVELDEBUG=$(($(kill -l RTMIN) + 22))
  kill -n $LOGLEVELDEBUG 1
  
  while true; do
        # use discovery to activate systemd
        iscsiadm -m discovery -t st -p 192.168.122.1
        sleep 2
        systemctl stop iscsid.service
        if [ $? -ne 0 ]; then
                exit $?
        fi
        sleep 2
  done
  
  journalctl -b -x -u iscsid.service -u iscsid.socket | gzip > systemd-iscsid.gz
---

Here's the journal output from the final, failing, pass
(bear with me, this is kind of long)

TL;DR - systemd starts listening on the admin socket again before it
even runs iscsiadm, and the IMMEDIATE_STOP command actually enqueues a
service start job.

This first part starts iscsid via socket activation, no problems

  systemd[1]: Incoming traffic on iscsid.socket
  systemd[1]: Trying to enqueue job iscsid.service/start/replace
  systemd[1]: Installed new job iscsid.service/start as 6572
  systemd[1]: Enqueued job iscsid.service/start as 6572
  systemd[1]: iscsid.socket changed listening -> running
  systemd[1]: Starting Open-iSCSI...
  -- Subject: Unit iscsid.service has begun with start-up
  -- Defined-By: systemd
  -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
  -- 
  -- Unit iscsid.service has begun starting up.
  systemd[1]: About to execute: /usr/sbin/iscsid -f
  systemd[1]: Forked /usr/sbin/iscsid as 27674
  systemd[1]: iscsid.service changed dead -> running
  systemd[27674]: Executing: /usr/sbin/iscsid -f
  systemd[1]: Job iscsid.service/start finished, result=done
  systemd[1]: Started Open-iSCSI.
  -- Subject: Unit iscsid.service has finished start-up
  -- Defined-By: systemd
  -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
  -- 
  -- Unit iscsid.service has finished starting up.
  -- 
  -- The start-up result is done.

Now systemd is sent the stop command

  systemd[1]: Trying to enqueue job iscsid.service/stop/replace
  systemd[1]: Installed new job iscsid.service/stop as 6577
  systemd[1]: Enqueued job iscsid.service/stop as 6577
  systemd[1]: Stopping Open-iSCSI...
  -- Subject: Unit iscsid.service has begun shutting down
  -- Defined-By: systemd
  -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
  -- 
  -- Unit iscsid.service has begun shutting down.

systemd forks a new process in preparation to run the ExecStop

  systemd[1]: About to execute: /sbin/iscsiadm -k 0 2
  systemd[1]: Forked /sbin/iscsiadm as 27679

but then goes ahead and declares the service stopped

  systemd[1]: iscsid.service changed running -> stop
  systemd[1]: iscsid.socket got notified about service death (failed 
permanently: no)

and starts listening on the socket already

  systemd[1]: iscsid.socket changed running -> listening

and now actually gets around to execing iscsiadm

  systemd[27679]: Executing: /sbin/iscsiadm -k 0 2

and the socket unit sees the MGMT_IPC_IMMEDIATE_STOP command as a reason
to _start_ iscsid.service

  systemd[1]: Incoming traffic on iscsid.socket
  systemd[1]: Trying to enqueue job iscsid.service/start/replace

the stop job isn't finished, but we've got a start job now so cancel it

  systemd[1]: Job iscsid.service/stop finished, result=canceled
  systemd[1]: Installed new job iscsid.service/start as 6579
  systemd[1]: Enqueued job iscsid.service/start as 6579
  systemd[1]: iscsid.socket changed listening -> running
  systemd[1]: Child 27674 belongs to iscsid.service

iscsid goes ahead and exists, as it was told to

  systemd[1]: iscsid.service: main process exited, code=exited, status=0/SUCCESS
  systemd[1]: Child 27679 belongs to iscsid.service
  systemd[1]: iscsid.service: control process exited, code=exited status=0
  systemd[1]: iscsid.service got final SIGCHLD for state stop
  systemd[1]: iscsid.service changed stop -> dead
  systemd[1]: iscsid.socket got notified about service death (failed 
permanently: no)
  systemd[1]: iscsid.socket changed running -> listening
  systemd[1]: iscsid.service: cgroup is empty
  iscsid[27674]: iscsid: iscsid shutting down.

but remember that start job that got enqueued

  systemd[1]: Starting Open-iSCSI...
  -- Subject: Unit iscsid.service has begun with start-up
  -- Defined-By: systemd
  -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
  -- 
  -- Unit iscsid.service has begun starting up.
  systemd[1]: About to execute: /usr/sbin/iscsid -f
  systemd[1]: Forked /usr/sbin/iscsid as 27682
  systemd[1]: iscsid.service changed dead -> running
  systemd[1]: Job iscsid.service/start finished, result=done
  systemd[1]: Started Open-iSCSI.
  -- Subject: Unit iscsid.service has finished start-up
  -- Defined-By: systemd
  -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
  -- 
  -- Unit iscsid.service has finished starting up.
  -- 
  -- The start-up result is done.
  systemd[1]: iscsid.socket changed listening -> running
  systemd[27682]: Executing: /usr/sbin/iscsid -f

-- 
You received this message because you are subscribed to the Google Groups 
"open-iscsi" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to open-iscsi+unsubscr...@googlegroups.com.
To post to this group, send email to open-iscsi@googlegroups.com.
Visit this group at http://groups.google.com/group/open-iscsi.
For more options, visit https://groups.google.com/d/optout.

Reply via email to