systemd: Is it wrong?

["Jóhann B. Guðmundsson"]

On 07/08/2011 10:47 AM, Neil Horman wrote:
> On Thu, Jul 07, 2011 at 10:57:54PM -0400, Steve Dickson wrote:
>> Hello,
>>
>> One of the maintainers of systemd and I  have been working
>> together on trying to convert the NFS SysV init scripts
>> into systemd services. Here is the long trail...
>>
>> https://bugzilla.redhat.com/show_bug.cgi?id=699040
>>
>> The point is this, with fairly complicated system,
>> some events need to have happen, like loading modules,
>> before other events happen, like setting parameters of
>> those loaded modules.
>>
>> Currently the ExecStart commands can be started and end
>> before the ExecStartPre even start. This means setting
>> modules parameters within the same service file are
>> impossible.
>>
> I would have though intuitively that Pre commands would complete prior to
> ExecStart command in the same service file.  To not do so seems like a bug to
> me.
> Neil
>

What I think got him confused was the order of execution he saw in the 
status output which is reversed as in the first run command is at the 
bottom and the last run command on the top..

A simple test case show that the commands are correctly ordered and 
executed sequentially and after the other one has finished...

[Unit]
Description=Test ordering + time of Exec

[Service]
Type=oneshot
ExecStartPre=/usr/bin/logger 1
ExecStartPre=/bin/sleep 1
ExecStartPre=/usr/bin/logger 2
ExecStartPre=/bin/sleep 2
ExecStart=/usr/bin/logger 3
ExecStart=/bin/sleep 3
ExecStart=/usr/bin/logger 4
ExecStart=/bin/sleep 4
ExecStartPost=/usr/bin/logger 5
ExecStartPost=/bin/sleep 5
ExecStartPost=/usr/bin/logger 6
ExecStartPost=/bin/sleep 6
ExecStartPost=/usr/bin/logger 7
RemainAfterExit=yes

[root at valhalla system]# grep logger /var/log/messages
Jul  8 11:37:30 valhalla logger: 1
Jul  8 11:37:31 valhalla logger: 2 <-- waited for 1s
Jul  8 11:37:33 valhalla logger: 3 <-- waited for 2s
Jul  8 11:37:36 valhalla logger: 4 <-- waited for 3s
Jul  8 11:37:40 valhalla logger: 5 <-- waited for 4s
Jul  8 11:37:45 valhalla logger: 6 <-- waited for 5s
Jul  8 11:37:51 valhalla logger: 7 <-- waited for 6s
[root at valhalla system]#

test.service
       Loaded: loaded (/lib/systemd/system/test.service)
       Active: active (exited) since Fri, 08 Jul 2011 11:54:13 +0000; 3s ago
      Process: 8754 ExecStartPost=/usr/bin/logger 7 (code=exited, 
status=0/SUCCESS) <-- last
      Process: 8752 ExecStartPost=/bin/sleep 6 (code=exited, 
status=0/SUCCESS)
      Process: 8750 ExecStartPost=/usr/bin/logger 6 (code=exited, 
status=0/SUCCESS)
      Process: 8748 ExecStartPost=/bin/sleep 5 (code=exited, 
status=0/SUCCESS)
      Process: 8746 ExecStartPost=/usr/bin/logger 5 (code=exited, 
status=0/SUCCESS)
      Process: 8743 ExecStart=/bin/sleep 4 (code=exited, status=0/SUCCESS)
      Process: 8741 ExecStart=/usr/bin/logger 4 (code=exited, 
status=0/SUCCESS)
      Process: 8739 ExecStart=/bin/sleep 3 (code=exited, status=0/SUCCESS)
      Process: 8737 ExecStart=/usr/bin/logger 3 (code=exited, 
status=0/SUCCESS)
      Process: 8735 ExecStartPre=/bin/sleep 2 (code=exited, 
status=0/SUCCESS)
      Process: 8733 ExecStartPre=/usr/bin/logger 2 (code=exited, 
status=0/SUCCESS)
      Process: 8731 ExecStartPre=/bin/sleep 1 (code=exited, 
status=0/SUCCESS)
      Process: 8729 ExecStartPre=/usr/bin/logger 1 (code=exited, 
status=0/SUCCESS) <--- first
       CGroup: name=systemd:/system/test.service


JBG