salt: Dry-running state.highstate only returns the first change

Hello

When I run “state.highstate test=True” to dry-run changes, only the first change that would be made is displayed… is this a known behaviour or a bug?

For instance, when making several changes to states of a server and triggering a highstate command in dry-run mode (sorry for the long log traces):

root@tools-1:~# salt 'tools-1.*' state.highstate test=True
tools-1.*********.fr:
----------
          ID: packages.*********.fr.wheezy
    Function: pkgrepo.managed
        Name: deb http://packages.*********.fr/ wheezy main
      Result: True
     Comment: Package repo 'deb http://packages.*********.fr/ wheezy main' already configured
     Started: 21:46:20.479176
    Duration: 29.964 ms
     Changes:
----------
          ID: aptitude
    Function: pkg.installed
      Result: True
     Comment: Package aptitude is already installed.
     Started: 21:46:20.509282
    Duration: 206.965 ms
     Changes:
----------
          ID: /etc/apt/apt.conf.d/70debconf
    Function: file.managed
      Result: True
     Comment: The file /etc/apt/apt.conf.d/70debconf is in the correct state
     Started: 21:46:20.716388
    Duration: 2.223 ms
     Changes:
----------
          ID: bash-completion
    Function: pkg.installed
      Result: True
     Comment: Package bash-completion is already installed.
     Started: 21:46:20.718715
    Duration: 0.411 ms
     Changes:
----------
          ID: /etc/bash.bashrc
    Function: file.managed
      Result: True
     Comment: The file /etc/bash.bashrc is in the correct state
     Started: 21:46:20.719221
    Duration: 1.56 ms
     Changes:
----------
          ID: less
    Function: pkg.installed
      Result: True
     Comment: Package less is already installed.
     Started: 21:46:20.720880
    Duration: 0.381 ms
     Changes:
----------
          ID: /etc/profile.d/less.sh
    Function: file.managed
      Result: None
     Comment: The following values are set to be changed:
              newfile: /etc/profile.d/less.sh
     Started: 21:46:20.721546
    Duration: 1.434 ms
     Changes:

Summary
------------
Succeeded: 7 (unchanged=1)
Failed:    0
------------
Total states run:     7

Same locally using salt-call:

root@tools-1:~# salt-call state.highstate test=True
[INFO    ] Loading fresh modules for state activity
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://top.sls'
[INFO    ] Creating module dir '/var/cache/salt/minion/extmods/modules'
[INFO    ] Syncing modules for environment 'base'
[INFO    ] Loading cache from salt://_modules, for base)
[INFO    ] Caching directory '_modules/' for environment 'base'
[INFO    ] Creating module dir '/var/cache/salt/minion/extmods/states'
[INFO    ] Syncing states for environment 'base'
[INFO    ] Loading cache from salt://_states, for base)
[INFO    ] Caching directory '_states/' for environment 'base'
[INFO    ] Creating module dir '/var/cache/salt/minion/extmods/grains'
[INFO    ] Syncing grains for environment 'base'
[INFO    ] Loading cache from salt://_grains, for base)
[INFO    ] Caching directory '_grains/' for environment 'base'
[INFO    ] Creating module dir '/var/cache/salt/minion/extmods/renderers'
[INFO    ] Syncing renderers for environment 'base'
[INFO    ] Loading cache from salt://_renderers, for base)
[INFO    ] Caching directory '_renderers/' for environment 'base'
[INFO    ] Creating module dir '/var/cache/salt/minion/extmods/returners'
[INFO    ] Syncing returners for environment 'base'
[INFO    ] Loading cache from salt://_returners, for base)
[INFO    ] Caching directory '_returners/' for environment 'base'
[INFO    ] Creating module dir '/var/cache/salt/minion/extmods/outputters'
[INFO    ] Syncing outputters for environment 'base'
[INFO    ] Loading cache from salt://_outputters, for base)
[INFO    ] Caching directory '_outputters/' for environment 'base'
[INFO    ] Creating module dir '/var/cache/salt/minion/extmods/utils'
[INFO    ] Syncing utils for environment 'base'
[INFO    ] Loading cache from salt://_utils, for base)
[INFO    ] Caching directory '_utils/' for environment 'base'
[INFO    ] Loading fresh modules for state activity
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://core.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://apt/init.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://bash/init.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://less/init.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://motd/init.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://openntpd/init.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://openssh/init.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://salt/minion.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://ssh_keys.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://sysctl.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://syslog-ng/init.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://tmux/init.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://vim/init.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://salt/master.sls'
[INFO    ] Running state [deb http://packages.*********.fr/ wheezy main] at time 21:49:54.858680
[INFO    ] Executing state pkgrepo.managed for deb http://packages.*********.fr/ wheezy main
[INFO    ] Package repo 'deb http://packages.*********.fr/ wheezy main' already configured
[INFO    ] Completed state [deb http://packages.*********.fr/ wheezy main] at time 21:49:54.899099
[INFO    ] Running state [aptitude] at time 21:49:54.899255
[INFO    ] Executing state pkg.installed for aptitude
[INFO    ] Executing command "dpkg-query --showformat='${Status} ${Package} ${Version} ${Architecture}\n' -W" in directory '/root'
[INFO    ] Package aptitude is already installed.
[INFO    ] Completed state [aptitude] at time 21:49:55.101126
[INFO    ] Running state [/etc/apt/apt.conf.d/70debconf] at time 21:49:55.101314
[INFO    ] Executing state file.managed for /etc/apt/apt.conf.d/70debconf
[INFO    ] The file /etc/apt/apt.conf.d/70debconf is in the correct state
[INFO    ] Completed state [/etc/apt/apt.conf.d/70debconf] at time 21:49:55.103659
[INFO    ] Running state [bash-completion] at time 21:49:55.103795
[INFO    ] Executing state pkg.installed for bash-completion
[INFO    ] Package bash-completion is already installed.
[INFO    ] Completed state [bash-completion] at time 21:49:55.104290
[INFO    ] Running state [/etc/bash.bashrc] at time 21:49:55.104415
[INFO    ] Executing state file.managed for /etc/bash.bashrc
[INFO    ] The file /etc/bash.bashrc is in the correct state
[INFO    ] Completed state [/etc/bash.bashrc] at time 21:49:55.106120
[INFO    ] Running state [less] at time 21:49:55.106256
[INFO    ] Executing state pkg.installed for less
[INFO    ] Package less is already installed.
[INFO    ] Completed state [less] at time 21:49:55.106735
[INFO    ] Running state [/etc/profile.d/less.sh] at time 21:49:55.107049
[INFO    ] Executing state file.managed for /etc/profile.d/less.sh
[INFO    ] {'newfile': '/etc/profile.d/less.sh'}
[INFO    ] The following values are set to be changed:
newfile: /etc/profile.d/less.sh

[INFO    ] Completed state [/etc/profile.d/less.sh] at time 21:49:55.108679
local:
----------
          ID: packages.*********.fr.wheezy
    Function: pkgrepo.managed
        Name: deb http://packages.*********.fr/ wheezy main
      Result: True
     Comment: Package repo 'deb http://packages.*********.fr/ wheezy main' already configured
     Started: 21:49:54.858680
    Duration: 40.419 ms
     Changes:
----------
          ID: aptitude
    Function: pkg.installed
      Result: True
     Comment: Package aptitude is already installed.
     Started: 21:49:54.899255
    Duration: 201.871 ms
     Changes:
----------
          ID: /etc/apt/apt.conf.d/70debconf
    Function: file.managed
      Result: True
     Comment: The file /etc/apt/apt.conf.d/70debconf is in the correct state
     Started: 21:49:55.101314
    Duration: 2.345 ms
     Changes:
----------
          ID: bash-completion
    Function: pkg.installed
      Result: True
     Comment: Package bash-completion is already installed.
     Started: 21:49:55.103795
    Duration: 0.495 ms
     Changes:
----------
          ID: /etc/bash.bashrc
    Function: file.managed
      Result: True
     Comment: The file /etc/bash.bashrc is in the correct state
     Started: 21:49:55.104415
    Duration: 1.705 ms
     Changes:
----------
          ID: less
    Function: pkg.installed
      Result: True
     Comment: Package less is already installed.
     Started: 21:49:55.106256
    Duration: 0.479 ms
     Changes:
----------
          ID: /etc/profile.d/less.sh
    Function: file.managed
      Result: None
     Comment: The following values are set to be changed:
              newfile: /etc/profile.d/less.sh
     Started: 21:49:55.107049
    Duration: 1.63 ms
     Changes:

Summary
------------
Succeeded: 7 (unchanged=1)
Failed:    0
------------
Total states run:     7
root@tools-1:~#

But when triggering the highstate for real, much more changes occur:

root@tools-1:~# salt-call state.highstate
[INFO    ] Loading fresh modules for state activity
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://top.sls'
[INFO    ] Creating module dir '/var/cache/salt/minion/extmods/modules'
[INFO    ] Syncing modules for environment 'base'
[INFO    ] Loading cache from salt://_modules, for base)
[INFO    ] Caching directory '_modules/' for environment 'base'
[INFO    ] Creating module dir '/var/cache/salt/minion/extmods/states'
[INFO    ] Syncing states for environment 'base'
[INFO    ] Loading cache from salt://_states, for base)
[INFO    ] Caching directory '_states/' for environment 'base'
[INFO    ] Creating module dir '/var/cache/salt/minion/extmods/grains'
[INFO    ] Syncing grains for environment 'base'
[INFO    ] Loading cache from salt://_grains, for base)
[INFO    ] Caching directory '_grains/' for environment 'base'
[INFO    ] Creating module dir '/var/cache/salt/minion/extmods/renderers'
[INFO    ] Syncing renderers for environment 'base'
[INFO    ] Loading cache from salt://_renderers, for base)
[INFO    ] Caching directory '_renderers/' for environment 'base'
[INFO    ] Creating module dir '/var/cache/salt/minion/extmods/returners'
[INFO    ] Syncing returners for environment 'base'
[INFO    ] Loading cache from salt://_returners, for base)
[INFO    ] Caching directory '_returners/' for environment 'base'
[INFO    ] Creating module dir '/var/cache/salt/minion/extmods/outputters'
[INFO    ] Syncing outputters for environment 'base'
[INFO    ] Loading cache from salt://_outputters, for base)
[INFO    ] Caching directory '_outputters/' for environment 'base'
[INFO    ] Creating module dir '/var/cache/salt/minion/extmods/utils'
[INFO    ] Syncing utils for environment 'base'
[INFO    ] Loading cache from salt://_utils, for base)
[INFO    ] Caching directory '_utils/' for environment 'base'
[INFO    ] Loading fresh modules for state activity
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://core.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://apt/init.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://bash/init.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://less/init.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://motd/init.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://openntpd/init.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://openssh/init.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://salt/minion.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://ssh_keys.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://sysctl.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://syslog-ng/init.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://tmux/init.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://vim/init.sls'
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://salt/master.sls'
[INFO    ] Running state [deb http://packages.*********.fr/ wheezy main] at time 21:52:08.498498
[INFO    ] Executing state pkgrepo.managed for deb http://packages.*********.fr/ wheezy main
[INFO    ] Package repo 'deb http://packages.*********.fr/ wheezy main' already configured
[INFO    ] Completed state [deb http://packages.*********.fr/ wheezy main] at time 21:52:08.539240
[INFO    ] Running state [aptitude] at time 21:52:08.539399
[INFO    ] Executing state pkg.installed for aptitude
[INFO    ] Executing command "dpkg-query --showformat='${Status} ${Package} ${Version} ${Architecture}\n' -W" in directory '/root'
[INFO    ] Package aptitude is already installed.
[INFO    ] Completed state [aptitude] at time 21:52:08.743050
[INFO    ] Running state [/etc/apt/apt.conf.d/70debconf] at time 21:52:08.743248
[INFO    ] Executing state file.managed for /etc/apt/apt.conf.d/70debconf
[INFO    ] File /etc/apt/apt.conf.d/70debconf is in the correct state
[INFO    ] Completed state [/etc/apt/apt.conf.d/70debconf] at time 21:52:08.745457
[INFO    ] Running state [bash-completion] at time 21:52:08.745585
[INFO    ] Executing state pkg.installed for bash-completion
[INFO    ] Package bash-completion is already installed.
[INFO    ] Completed state [bash-completion] at time 21:52:08.746064
[INFO    ] Running state [/etc/bash.bashrc] at time 21:52:08.746188
[INFO    ] Executing state file.managed for /etc/bash.bashrc
[INFO    ] File /etc/bash.bashrc is in the correct state
[INFO    ] Completed state [/etc/bash.bashrc] at time 21:52:08.748258
[INFO    ] Running state [less] at time 21:52:08.748392
[INFO    ] Executing state pkg.installed for less
[INFO    ] Package less is already installed.
[INFO    ] Completed state [less] at time 21:52:08.748876
[INFO    ] Running state [/etc/profile.d/less.sh] at time 21:52:08.749193
[INFO    ] Executing state file.managed for /etc/profile.d/less.sh
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://less/files/etc/profile.d/less.sh'
[INFO    ] File changed:
New file
[INFO    ] Completed state [/etc/profile.d/less.sh] at time 21:52:09.074892
[INFO    ] Running state [/etc/motd] at time 21:52:09.075189
[INFO    ] Executing state file.managed for /etc/motd
[INFO    ] File /etc/motd is in the correct state
[INFO    ] Completed state [/etc/motd] at time 21:52:09.078376
[INFO    ] Running state [openntpd] at time 21:52:09.078657
[INFO    ] Executing state pkg.installed for openntpd
[INFO    ] Package openntpd is already installed.
[INFO    ] Completed state [openntpd] at time 21:52:09.079780
[INFO    ] Running state [/etc/openntpd/ntpd.conf] at time 21:52:09.080043
[INFO    ] Executing state file.managed for /etc/openntpd/ntpd.conf
[INFO    ] File /etc/openntpd/ntpd.conf is in the correct state
[INFO    ] Completed state [/etc/openntpd/ntpd.conf] at time 21:52:09.083006
[INFO    ] Running state [openssh-server] at time 21:52:09.083289
[INFO    ] Executing state pkg.installed for openssh-server
[INFO    ] Package openssh-server is already installed.
[INFO    ] Completed state [openssh-server] at time 21:52:09.084335
[INFO    ] Running state [/etc/ssh/sshd_config] at time 21:52:09.084595
[INFO    ] Executing state file.managed for /etc/ssh/sshd_config
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://openssh/templates/sshd_config.jinja'
[INFO    ] File /etc/ssh/sshd_config is in the correct state
[INFO    ] Completed state [/etc/ssh/sshd_config] at time 21:52:09.093154
[INFO    ] Running state [salt-minion] at time 21:52:09.093412
[INFO    ] Executing state pkg.installed for salt-minion
[INFO    ] Version 2014.7.0+ds-2~bpo70+1 of package 'salt-minion' is already installed.
[INFO    ] Completed state [salt-minion] at time 21:52:09.094354
[INFO    ] Running state [salt-minion] at time 21:52:09.094595
[INFO    ] Executing state service.running for salt-minion
[INFO    ] Executing command 'runlevel' in directory '/root'
[INFO    ] Executing command 'service salt-minion status' in directory '/root'
[INFO    ] The service salt-minion is already running
[INFO    ] Completed state [salt-minion] at time 21:52:09.118178
[INFO    ] Running state [/etc/salt/minion] at time 21:52:09.118479
[INFO    ] Executing state file.managed for /etc/salt/minion
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://salt/templates/minion.jinja'
[INFO    ] File changed:

---
+++
@@ -10,7 +10,7 @@
 # Per default the minion will automatically include all config files
 # from minion.d/*.conf (minion.d is a directory in the same directory
 # as the main minion config file).
-#default_include: minion.d/*.conf
+default_include: minion.d/*.conf

 # Set the location of the salt master server, if the master server cannot be
 # resolved, then the minion will fail to start.

[INFO    ] Completed state [/etc/salt/minion] at time 21:52:09.137354
[INFO    ] Running state [AAAAB3NzaC1yc2EAAAABIwAAAQEAvblupjNT3ctwB4Y3fylHRiNe1ObWipEfy/aYNx7lfFwJKM+3Ub0tqhUHxaG8sacgPKxB5bt2QVY7RavtGe+5UDg80QLCSfkbEgp8tr/x.....................] at time 21:52:09.137587
[INFO    ] Executing state ssh_auth.present for AAAAB3NzaC1yc2EAAAABIwAAAQEAvblupjNT3ctwB4Y3fylHRiNe1ObWipEfy/aYNx7lfFwJKM+3Ub0tqhUHxaG8sacgPKxB5bt2QVY7RavtGe+5UDg80QLCSfkbEgp8tr/x.....................
[INFO    ] The authorized host key AAAAB3NzaC1yc2EAAAABIwAAAQEAvblupjNT3ctwB4Y3fylHRiNe1ObWipEfy/aYNx7lfFwJKM+3Ub0tqhUHxaG8sacgPKxB5bt2QVY7RavtGe+5UDg80QLCSfkbEgp8tr/x..................... is already present for user root
[INFO    ] Completed state [AAAAB3NzaC1yc2EAAAABIwAAAQEAvblupjNT3ctwB4Y3fylHRiNe1ObWipEfy/aYNx7lfFwJKM+3Ub0tqhUHxaG8sacgPKxB5bt2QVY7RavtGe+5UDg80QLCSfkbEgp8tr/x.....................] at time 21:52:09.139750
[INFO    ] Running state [kernel.dmesg_restrict] at time 21:52:09.140012
[INFO    ] Executing state sysctl.present for kernel.dmesg_restrict
[INFO    ] Executing command 'sysctl -a' in directory '/root'
[INFO    ] Executing command 'sysctl -a' in directory '/root'
[INFO    ] Sysctl value kernel.dmesg_restrict = 1 is already set
[INFO    ] Completed state [kernel.dmesg_restrict] at time 21:52:09.222078
[INFO    ] Running state [AAAAB3NzaC1yc2EAAAADAQABAAABAQDFh6kfcJ7wf2AywaiiTVpn2yCBJUvK/XZkMln28x2x2dGp+WZ8GNOIUbeoUMHi0tzxpL9J+7wK4rtrxJ...........................] at time 21:52:09.222349
[INFO    ] Executing state ssh_auth.present for AAAAB3NzaC1yc2EAAAADAQABAAABAQDFh6kfcJ7wf2AywaiiTVpn2yCBJUvK/XZkMln28x2x2dGp+WZ8GNOIUbeoUMHi0tzxpL9J+7wK4rtrxJ...........................
[INFO    ] The authorized host key AAAAB3NzaC1yc2EAAAADAQABAAABAQDFh6kfcJ7wf2AywaiiTVpn2yCBJUvK/XZkMln28x2x2dGp+WZ8GNOIUbeoUMHi0tzxpL9J+7wK4rtrxJ........................... is already present for user root
[INFO    ] Completed state [AAAAB3NzaC1yc2EAAAADAQABAAABAQDFh6kfcJ7wf2AywaiiTVpn2yCBJUvK/XZkMln28x2x2dGp+WZ8GNOIUbeoUMHi0tzxpL9J+7wK4rtrxJ...........................] at time 21:52:09.224093
[INFO    ] Running state [vm.swappiness] at time 21:52:09.224312
[INFO    ] Executing state sysctl.present for vm.swappiness
[INFO    ] Executing command 'sysctl -a' in directory '/root'
[INFO    ] Executing command 'sysctl -a' in directory '/root'
[INFO    ] Sysctl value vm.swappiness = 0 is already set
[INFO    ] Completed state [vm.swappiness] at time 21:52:09.292243
[INFO    ] Running state [fs.protected_hardlinks] at time 21:52:09.292465
[INFO    ] Executing state sysctl.present for fs.protected_hardlinks
[INFO    ] Executing command 'sysctl -a' in directory '/root'
[INFO    ] Executing command 'sysctl -a' in directory '/root'
[INFO    ] Sysctl value fs.protected_hardlinks = 1 is already set
[INFO    ] Completed state [fs.protected_hardlinks] at time 21:52:09.353007
[INFO    ] Running state [fs.protected_symlinks] at time 21:52:09.353213
[INFO    ] Executing state sysctl.present for fs.protected_symlinks
[INFO    ] Executing command 'sysctl -a' in directory '/root'
[INFO    ] Executing command 'sysctl -a' in directory '/root'
[INFO    ] Sysctl value fs.protected_symlinks = 1 is already set
[INFO    ] Completed state [fs.protected_symlinks] at time 21:52:09.410497
[INFO    ] Running state [syslog-ng_packages] at time 21:52:09.411279
[INFO    ] Executing state pkg.installed for syslog-ng_packages
[INFO    ] All specified packages are already installed.
[INFO    ] Completed state [syslog-ng_packages] at time 21:52:09.412016
[INFO    ] Running state [rsyslog] at time 21:52:09.412301
[INFO    ] Executing state pkg.purged for rsyslog
[INFO    ] None of the targeted packages are installed or partially installed
[INFO    ] Completed state [rsyslog] at time 21:52:09.412831
[INFO    ] Running state [/etc/default/syslog-ng] at time 21:52:09.412965
[INFO    ] Executing state file.managed for /etc/default/syslog-ng
[INFO    ] File /etc/default/syslog-ng is in the correct state
[INFO    ] Completed state [/etc/default/syslog-ng] at time 21:52:09.415065
[INFO    ] Running state [/etc/logrotate.d/syslog-ng] at time 21:52:09.415203
[INFO    ] Executing state file.managed for /etc/logrotate.d/syslog-ng
[INFO    ] File /etc/logrotate.d/syslog-ng is in the correct state
[INFO    ] Completed state [/etc/logrotate.d/syslog-ng] at time 21:52:09.417225
[INFO    ] Running state [/etc/syslog-ng/syslog-ng.conf] at time 21:52:09.417522
[INFO    ] Executing state file.managed for /etc/syslog-ng/syslog-ng.conf
[INFO    ] File /etc/syslog-ng/syslog-ng.conf is in the correct state
[INFO    ] Completed state [/etc/syslog-ng/syslog-ng.conf] at time 21:52:09.419449
[INFO    ] Running state [/etc/syslog-ng/conf.d/00-common.conf] at time 21:52:09.419746
[INFO    ] Executing state file.managed for /etc/syslog-ng/conf.d/00-common.conf
[INFO    ] Fetching file from saltenv 'base', ** skipped ** latest already in cache 'salt://syslog-ng/files/etc/syslog-ng/conf.d/00-common.conf'
[INFO    ] File changed:

---
+++
@@ -3,6 +3,12 @@
 #   THIS FILE IS MANAGED BY SALT, ALL LOCAL EDITS WILL BE OVERWRITTEN !
 #
 # /!\ /!\ /!\ /!\ /!\ /!\ /!\ /!\ /!\ /!\ /!\ /!\ /!\ /!\ /!\ /!\ /!\ /!\
+
+source s_local {
+   internal();
+   unix-dgram("/dev/log");
+   file("/proc/kmsg" program-override("kernel") flags(kernel));
+};

 filter f_facility_auth { facility(auth, authpriv); };
 filter f_facility_cron { facility(cron); };

[INFO    ] Completed state [/etc/syslog-ng/conf.d/00-common.conf] at time 21:52:09.424061
[INFO    ] Running state [/etc/syslog-ng/conf.d/10-discard.conf] at time 21:52:09.424358
[INFO    ] Executing state file.managed for /etc/syslog-ng/conf.d/10-discard.conf
[INFO    ] File /etc/syslog-ng/conf.d/10-discard.conf is in the correct state
[INFO    ] Completed state [/etc/syslog-ng/conf.d/10-discard.conf] at time 21:52:09.425953
[INFO    ] Running state [/etc/syslog-ng/conf.d/90-default.conf] at time 21:52:09.426247
[INFO    ] Executing state file.managed for /etc/syslog-ng/conf.d/90-default.conf
[INFO    ] File /etc/syslog-ng/conf.d/90-default.conf is in the correct state
[INFO    ] Completed state [/etc/syslog-ng/conf.d/90-default.conf] at time 21:52:09.427734
[INFO    ] Running state [syslog-ng] at time 21:52:09.427867
[INFO    ] Executing state service.running for syslog-ng
[INFO    ] Executing command 'runlevel' in directory '/root'
[INFO    ] Executing command 'service syslog-ng status' in directory '/root'
[INFO    ] The service syslog-ng is already running
[INFO    ] Completed state [syslog-ng] at time 21:52:09.442683
[INFO    ] Running state [tmux] at time 21:52:09.442854
[INFO    ] Executing state pkg.installed for tmux
[INFO    ] Package tmux is already installed.
[INFO    ] Completed state [tmux] at time 21:52:09.443565
[INFO    ] Running state [/etc/tmux.conf] at time 21:52:09.443903
[INFO    ] Executing state file.managed for /etc/tmux.conf
[INFO    ] File /etc/tmux.conf is in the correct state
[INFO    ] Completed state [/etc/tmux.conf] at time 21:52:09.446387
[INFO    ] Running state [vim-nox] at time 21:52:09.446515
[INFO    ] Executing state pkg.installed for vim-nox
[INFO    ] Package vim-nox is already installed.
[INFO    ] Completed state [vim-nox] at time 21:52:09.446995
[INFO    ] Running state [/etc/vim/vimrc.local] at time 21:52:09.447402
[INFO    ] Executing state file.managed for /etc/vim/vimrc.local
[INFO    ] File /etc/vim/vimrc.local is in the correct state
[INFO    ] Completed state [/etc/vim/vimrc.local] at time 21:52:09.449561
[INFO    ] Running state [Europe/Paris] at time 21:52:09.449699
[INFO    ] Executing state timezone.system for Europe/Paris
[INFO    ] Executing command 'grep "UTC=" /etc/default/rcS | grep -vE "^#"' in directory '/root'
[INFO    ] Executing command 'tail -n 1 /etc/adjtime' in directory '/root'
[INFO    ] Timezone Europe/Paris already set, UTC already set to Europe/Paris
[INFO    ] Completed state [Europe/Paris] at time 21:52:09.459954
[INFO    ] Running state [tools] at time 21:52:09.460122
[INFO    ] Executing state pkg.installed for tools
[INFO    ] All specified packages are already installed.
[INFO    ] Completed state [tools] at time 21:52:09.460909
[INFO    ] Running state [salt-master] at time 21:52:09.461029
[INFO    ] Executing state pkg.installed for salt-master
[INFO    ] Version 2014.7.0+ds-2~bpo70+1 of package 'salt-master' is already installed.
[INFO    ] Completed state [salt-master] at time 21:52:09.461495
[INFO    ] Running state [salt-master] at time 21:52:09.461614
[INFO    ] Executing state service.running for salt-master
[INFO    ] Executing command 'runlevel' in directory '/root'
[INFO    ] Executing command 'service salt-master status' in directory '/root'
[INFO    ] The service salt-master is already running
[INFO    ] Completed state [salt-master] at time 21:52:09.475876
[INFO    ] Running state [/etc/salt/master] at time 21:52:09.476045
[INFO    ] Executing state file.managed for /etc/salt/master
[INFO    ] File /etc/salt/master is in the correct state
[INFO    ] Completed state [/etc/salt/master] at time 21:52:09.478707
local:
----------
          ID: packages.*********.fr.wheezy
    Function: pkgrepo.managed
        Name: deb http://packages.*********.fr/ wheezy main
      Result: True
     Comment: Package repo 'deb http://packages.*********.fr/ wheezy main' already configured
     Started: 21:52:08.498498
    Duration: 40.742 ms
     Changes:
----------
          ID: aptitude
    Function: pkg.installed
      Result: True
     Comment: Package aptitude is already installed.
     Started: 21:52:08.539399
    Duration: 203.651 ms
     Changes:
----------
          ID: /etc/apt/apt.conf.d/70debconf
    Function: file.managed
      Result: True
     Comment: File /etc/apt/apt.conf.d/70debconf is in the correct state
     Started: 21:52:08.743248
    Duration: 2.209 ms
     Changes:
----------
          ID: bash-completion
    Function: pkg.installed
      Result: True
     Comment: Package bash-completion is already installed.
     Started: 21:52:08.745585
    Duration: 0.479 ms
     Changes:
----------
          ID: /etc/bash.bashrc
    Function: file.managed
      Result: True
     Comment: File /etc/bash.bashrc is in the correct state
     Started: 21:52:08.746188
    Duration: 2.07 ms
     Changes:
----------
          ID: less
    Function: pkg.installed
      Result: True
     Comment: Package less is already installed.
     Started: 21:52:08.748392
    Duration: 0.484 ms
     Changes:
----------
          ID: /etc/profile.d/less.sh
    Function: file.managed
      Result: True
     Comment: File /etc/profile.d/less.sh updated
     Started: 21:52:08.749193
    Duration: 325.699 ms
     Changes:
              ----------
              diff:
                  New file
              mode:
                  0644
----------
          ID: /etc/motd
    Function: file.managed
      Result: True
     Comment: File /etc/motd is in the correct state
     Started: 21:52:09.075189
    Duration: 3.187 ms
     Changes:
----------
          ID: openntpd
    Function: pkg.installed
      Result: True
     Comment: Package openntpd is already installed.
     Started: 21:52:09.078657
    Duration: 1.123 ms
     Changes:
----------
          ID: /etc/openntpd/ntpd.conf
    Function: file.managed
      Result: True
     Comment: File /etc/openntpd/ntpd.conf is in the correct state
     Started: 21:52:09.080043
    Duration: 2.963 ms
     Changes:
----------
          ID: openssh-server
    Function: pkg.installed
      Result: True
     Comment: Package openssh-server is already installed.
     Started: 21:52:09.083289
    Duration: 1.046 ms
     Changes:
----------
          ID: /etc/ssh/sshd_config
    Function: file.managed
      Result: True
     Comment: File /etc/ssh/sshd_config is in the correct state
     Started: 21:52:09.084595
    Duration: 8.559 ms
     Changes:
----------
          ID: salt-minion
    Function: pkg.installed
      Result: True
     Comment: Version 2014.7.0+ds-2~bpo70+1 of package 'salt-minion' is already installed.
     Started: 21:52:09.093412
    Duration: 0.942 ms
     Changes:
----------
          ID: salt-minion
    Function: service.running
      Result: True
     Comment: The service salt-minion is already running
     Started: 21:52:09.094595
    Duration: 23.583 ms
     Changes:
----------
          ID: /etc/salt/minion
    Function: file.managed
      Result: True
     Comment: File /etc/salt/minion updated
     Started: 21:52:09.118479
    Duration: 18.875 ms
     Changes:
              ----------
              diff:
                  ---
                  +++
                  @@ -10,7 +10,7 @@
                   # Per default the minion will automatically include all config files
                   # from minion.d/*.conf (minion.d is a directory in the same directory
                   # as the main minion config file).
                  -#default_include: minion.d/*.conf
                  +default_include: minion.d/*.conf

                   # Set the location of the salt master server, if the master server cannot be
                   # resolved, then the minion will fail to start.

----------
          ID: ssh_keys_for_root
    Function: ssh_auth.present
        Name: AAAAB3NzaC1yc2EAAAABIwAAAQEAvblupjNT3ctwB4Y3fylHRiNe1ObWipEfy/aYNx7lfFwJKM+3Ub0tqhUHxaG8sacgPKxB5bt2QVY7RavtGe+5UDg80QLCSfkbEgp8tr/.........................
      Result: True
     Comment: The authorized host key AAAAB3NzaC1yc2EAAAABIwAAAQEAvblupjNT3ctwB4Y3fylHRiNe1ObWipEfy/aYNx7lfFwJKM+3Ub0tqhUHxaG8sacgPKxB5bt2QVY7RavtGe+5UDg80QLCSfkbEgp8tr/...................... is already present for user root
     Started: 21:52:09.137587
    Duration: 2.163 ms
     Changes:
----------
          ID: sysctl_kernel.dmesg_restrict
    Function: sysctl.present
        Name: kernel.dmesg_restrict
      Result: True
     Comment: Sysctl value kernel.dmesg_restrict = 1 is already set
     Started: 21:52:09.140012
    Duration: 82.066 ms
     Changes:
----------
          ID: ssh_keys_for_root
    Function: ssh_auth.present
        Name: AAAAB3NzaC1yc2EAAAADAQABAAABAQDFh6kfcJ7wf2AywaiiTVpn2yCBJUvK/XZkMln28x2x2dGp+WZ8GNOIUbeoUMHi0tzxpL9J+7wK4rtrxJ93cpU1ECBS1G....................
      Result: True
     Comment: The authorized host key AAAAB3NzaC1yc2EAAAADAQABAAABAQDFh6kfcJ7wf2AywaiiTVpn2yCBJUvK/XZkMln28x2x2dGp+WZ8GNOIUbeoUMHi0tzxpL9J+7wK4rtrxJ93cpU1ECBS1G.................... is already present for user root
     Started: 21:52:09.222349
    Duration: 1.744 ms
     Changes:
----------
          ID: sysctl_vm.swappiness
    Function: sysctl.present
        Name: vm.swappiness
      Result: True
     Comment: Sysctl value vm.swappiness = 0 is already set
     Started: 21:52:09.224312
    Duration: 67.931 ms
     Changes:
----------
          ID: sysctl_fs.protected_hardlinks
    Function: sysctl.present
        Name: fs.protected_hardlinks
      Result: True
     Comment: Sysctl value fs.protected_hardlinks = 1 is already set
     Started: 21:52:09.292465
    Duration: 60.542 ms
     Changes:
----------
          ID: sysctl_fs.protected_symlinks
    Function: sysctl.present
        Name: fs.protected_symlinks
      Result: True
     Comment: Sysctl value fs.protected_symlinks = 1 is already set
     Started: 21:52:09.353213
    Duration: 57.284 ms
     Changes:
----------
          ID: syslog-ng_packages
    Function: pkg.installed
      Result: True
     Comment: All specified packages are already installed.
     Started: 21:52:09.411279
    Duration: 0.737 ms
     Changes:
----------
          ID: rsyslog
    Function: pkg.purged
      Result: True
     Comment: None of the targeted packages are installed or partially installed
     Started: 21:52:09.412301
    Duration: 0.53 ms
     Changes:
----------
          ID: /etc/default/syslog-ng
    Function: file.managed
      Result: True
     Comment: File /etc/default/syslog-ng is in the correct state
     Started: 21:52:09.412965
    Duration: 2.1 ms
     Changes:
----------
          ID: /etc/logrotate.d/syslog-ng
    Function: file.managed
      Result: True
     Comment: File /etc/logrotate.d/syslog-ng is in the correct state
     Started: 21:52:09.415203
    Duration: 2.022 ms
     Changes:
----------
          ID: /etc/syslog-ng/syslog-ng.conf
    Function: file.managed
      Result: True
     Comment: File /etc/syslog-ng/syslog-ng.conf is in the correct state
     Started: 21:52:09.417522
    Duration: 1.927 ms
     Changes:
----------
          ID: /etc/syslog-ng/conf.d/00-common.conf
    Function: file.managed
      Result: True
     Comment: File /etc/syslog-ng/conf.d/00-common.conf updated
     Started: 21:52:09.419746
    Duration: 4.315 ms
     Changes:
              ----------
              diff:
                  ---
                  +++
                  @@ -3,6 +3,12 @@
                   #   THIS FILE IS MANAGED BY SALT, ALL LOCAL EDITS WILL BE OVERWRITTEN !
                   #
                   # /!\ /!\ /!\ /!\ /!\ /!\ /!\ /!\ /!\ /!\ /!\ /!\ /!\ /!\ /!\ /!\ /!\ /!\
                  +
                  +source s_local {
                  + internal();
                  + unix-dgram("/dev/log");
                  + file("/proc/kmsg" program-override("kernel") flags(kernel));
                  +};

                   filter f_facility_auth { facility(auth, authpriv); };
                   filter f_facility_cron { facility(cron); };

----------
          ID: /etc/syslog-ng/conf.d/10-discard.conf
    Function: file.managed
      Result: True
     Comment: File /etc/syslog-ng/conf.d/10-discard.conf is in the correct state
     Started: 21:52:09.424358
    Duration: 1.595 ms
     Changes:
----------
          ID: /etc/syslog-ng/conf.d/90-default.conf
    Function: file.managed
      Result: True
     Comment: File /etc/syslog-ng/conf.d/90-default.conf is in the correct state
     Started: 21:52:09.426247
    Duration: 1.487 ms
     Changes:
----------
          ID: syslog-ng
    Function: service.running
      Result: True
     Comment: The service syslog-ng is already running
     Started: 21:52:09.427867
    Duration: 14.816 ms
     Changes:
----------
          ID: tmux
    Function: pkg.installed
      Result: True
     Comment: Package tmux is already installed.
     Started: 21:52:09.442854
    Duration: 0.711 ms
     Changes:
----------
          ID: /etc/tmux.conf
    Function: file.managed
      Result: True
     Comment: File /etc/tmux.conf is in the correct state
     Started: 21:52:09.443903
    Duration: 2.484 ms
     Changes:
----------
          ID: vim-nox
    Function: pkg.installed
      Result: True
     Comment: Package vim-nox is already installed.
     Started: 21:52:09.446515
    Duration: 0.48 ms
     Changes:
----------
          ID: /etc/vim/vimrc.local
    Function: file.managed
      Result: True
     Comment: File /etc/vim/vimrc.local is in the correct state
     Started: 21:52:09.447402
    Duration: 2.159 ms
     Changes:
----------
          ID: timezone
    Function: timezone.system
        Name: Europe/Paris
      Result: True
     Comment: Timezone Europe/Paris already set, UTC already set to Europe/Paris
     Started: 21:52:09.449699
    Duration: 10.255 ms
     Changes:
----------
          ID: tools
    Function: pkg.installed
      Result: True
     Comment: All specified packages are already installed.
     Started: 21:52:09.460122
    Duration: 0.787 ms
     Changes:
----------
          ID: salt-master
    Function: pkg.installed
      Result: True
     Comment: Version 2014.7.0+ds-2~bpo70+1 of package 'salt-master' is already installed.
     Started: 21:52:09.461029
    Duration: 0.466 ms
     Changes:
----------
          ID: salt-master
    Function: service.running
      Result: True
     Comment: The service salt-master is already running
     Started: 21:52:09.461614
    Duration: 14.262 ms
     Changes:
----------
          ID: /etc/salt/master
    Function: file.managed
      Result: True
     Comment: File /etc/salt/master is in the correct state
     Started: 21:52:09.476045
    Duration: 2.662 ms
     Changes:

Summary
-------------
Succeeded: 39 (changed=3)
Failed:     0
-------------
Total states run:     39
root@tools-1:~#

I observed this behaviour on both 2014.1.11 and the new 2014.7.0, and it is reproducible every time. Am I missing something or is it possibly a bug?