Importing salt states fails ERF12-4701

Hi all,

I have configured Katello and Salt-master on the same server, and
refreshing features via HTTPS works fine, versions are

Katello 2.4 - which is running foreman 1.10.2
rubygem-smart_proxy_salt.noarch 2.1.6-1.el7
salt.noarch 2015.8.8-1.el7
salt-api.noarch 2015.8.8-1.el7
salt-master.noarch 2015.8.8-1.el7
tfm-rubygem-foreman_salt.noarch 4.0.1-1.fm1_10.el7

however if I try and import salt states via Configure > States I get the
following error from /var/log/foreman/production.log

> Started GET
"/salt/salt_modules/import?proxy=1-wellkatellodev-niwa-local" for
192.168.222.132 at 2016-03-29 14:29:07 +1300
2016-03-29 14:29:07 [app] [I] Processing by
ForemanSalt::SaltModulesController#import as HTML
2016-03-29 14:29:07 [app] [I] Parameters:
{"proxy"=>"1-wellkatellodev-niwa-local"}
2016-03-29 14:29:07 [app] [I] Redirected to
https://wellkatellodev.niwa.local/salt/salt_modules
2016-03-29 14:29:07 [app] [W] ProxyAPI operation FAILED
> ProxyAPI::ProxyException: ERF12-4701 [ProxyAPI::ProxyException]: Unable
to fetch Salt states list ([ProxyAPI::ProxyException]: ERF12-7301
[ProxyAPI::ProxyException]: Unable to fetch Salt environments list
([RestCli…) for proxy https://wellkatellodev.niwa.local:9090/salt/
>
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_salt-4.0.1/app/lib/proxy_api/salt.rb:43:in
rescue in states_list' > /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_salt-4.0.1/app/lib/proxy_api/salt.rb:35:instates_list'
>
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_salt-4.0.1/app/controllers/foreman_salt/state_importer.rb:16:in
fetch_states_from_proxy' > /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_salt-4.0.1/app/controllers/foreman_salt/salt_modules_controller.rb:60:inimport'
>
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/implicit_render.rb:4:in
send_action' > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/base.rb:167:inprocess_action'
>
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rendering.rb:10:in
process_action' > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/callbacks.rb:18:inblock in process_action'
>
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:649:in
block (4 levels) in _run__3678719368663148400__process_action__2542166424075117403__callbacks' > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:inblock in _conditional_callback_around_12188'
>
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:326:in
around' > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:310:in_callback_around_3693'
>
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in
_conditional_callback_around_12188' > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:626:inblock (3 levels) in
_run__3678719368663148400__process_action__2542166424075117403__callbacks'

(and so on)

in /var/log/foreman-proxy/proxy.log all I see is

D, [2016-03-29T14:29:07.312002 #3483] DEBUG – : accept:
192.168.14.100:33703
D, [2016-03-29T14:29:07.314182 #3483] DEBUG – : Rack::Handler::WEBrick is
invoked.
D, [2016-03-29T14:29:07.445111 #3483] DEBUG – : close: 192.168.14.100:33703

and that's with log_level set to DEBUG in /etc/foreman-proxy/settings.yml

/etc/salt/foreman.yaml

··· --- :proto: https :host: wellkatellodev.niwa.local :port: 443 :ssl_ca: "/var/lib/puppet/ssl/certs/ca.pem" :ssl_cert: "/var/lib/puppet/ssl/private_keys/wellkatellodev.niwa.local.pem" :ssl_key: "/var/lib/puppet/ssl/certs/wellkatellodev.niwa.local.pem" :timeout: 10 :salt: /usr/bin/salt :upload_grains: true

/etc/foreman-proxy/settings.d/salt.yml

:enabled: true
:autosign_file: /etc/salt/autosign.conf
:salt_command_user: root

Some features require using the Salt API - such as listing

environments and retrieving state info

:use_api: false
:api_url: https://wellkatellodev.niwa.local:9000
:api_auth: ldap
:api_username: zsaltuser
:api_password: removed

My salt-api is configured in /etc/salt/master as below

Salt-API configuration

rest_cherrypy:
port: 9000
ssl_crt: /var/lib/puppet/ssl/certs/wellkatellodev.niwa.local.pem
ssl_key: /var/lib/puppet/ssl/private_keys/wellkatellodev.niwa.local.pem

with external auth configured

external_auth:
ldap:
zsaltuser:
- .*

and an LDAP connection to our directory server configured. I can run “salt
-a ldap ‘*’ test.ping” commands specifying zsaltuser fine, and I can use
curl to query the salt-api

Any help much appreciated! :slight_smile:

Dylan

Note I found the following
http://projects.theforeman.org/issues/11360
http://projects.theforeman.org/issues/11433
http://projects.theforeman.org/issues/12426

but none provided me with an answer for my problem

> From: "Dylan Baars" <baarsd@gmail.com>
> To: "Foreman users" <foreman-users@googlegroups.com>
> Sent: Monday, March 28, 2016 9:49:20 PM
> Subject: [foreman-users] Importing salt states fails ERF12-4701
>
> Hi all,
>
> I have configured Katello and Salt-master on the same server, and
> refreshing features via HTTPS works fine, versions are
>
> Katello 2.4 - which is running foreman 1.10.2
> rubygem-smart_proxy_salt.noarch 2.1.6-1.el7
> salt.noarch 2015.8.8-1.el7
> salt-api.noarch 2015.8.8-1.el7
> salt-master.noarch 2015.8.8-1.el7
> tfm-rubygem-foreman_salt.noarch 4.0.1-1.fm1_10.el7
>
> however if I try and import salt states via Configure > States I get the
> following error from /var/log/foreman/production.log
>
> > Started GET
> "/salt/salt_modules/import?proxy=1-wellkatellodev-niwa-local" for
> 192.168.222.132 at 2016-03-29 14:29:07 +1300
> 2016-03-29 14:29:07 [app] [I] Processing by
> ForemanSalt::SaltModulesController#import as HTML
> 2016-03-29 14:29:07 [app] [I] Parameters:
> {"proxy"=>"1-wellkatellodev-niwa-local"}
> 2016-03-29 14:29:07 [app] [I] Redirected to
> https://wellkatellodev.niwa.local/salt/salt_modules
> 2016-03-29 14:29:07 [app] [W] ProxyAPI operation FAILED
> > ProxyAPI::ProxyException: ERF12-4701 [ProxyAPI::ProxyException]: Unable
> to fetch Salt states list ([ProxyAPI::ProxyException]: ERF12-7301
> [ProxyAPI::ProxyException]: Unable to fetch Salt environments list
> ([RestCli…) for proxy https://wellkatellodev.niwa.local:9090/salt/
> >
> /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_salt-4.0.1/app/lib/proxy_api/salt.rb:43:in
> rescue in states_list&#39; &gt; &gt; &gt; /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_salt-4.0.1/app/lib/proxy_api/salt.rb:35:in &gt; states_list'
> >
> /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_salt-4.0.1/app/controllers/foreman_salt/state_importer.rb:16:in
> fetch_states_from_proxy&#39; &gt; &gt; &gt; /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_salt-4.0.1/app/controllers/foreman_salt/salt_modules_controller.rb:60:in &gt; import'
> >
> /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/implicit_render.rb:4:in
> send_action&#39; &gt; &gt; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/base.rb:167:in &gt; process_action'
> >
> /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rendering.rb:10:in
> process_action&#39; &gt; &gt; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/callbacks.rb:18:in &gt; block in process_action'
> >
> /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:649:in
> block (4 levels) in &gt; _run__3678719368663148400__process_action__2542166424075117403__callbacks&#39; &gt; &gt; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in &gt; block in _conditional_callback_around_12188'
> >
> /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:326:in
> around&#39; &gt; &gt; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:310:in &gt; _callback_around_3693'
> >
> /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in
> _conditional_callback_around_12188&#39; &gt; &gt; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:626:in &gt; block (3 levels) in
> _run__3678719368663148400__process_action__2542166424075117403__callbacks'
>
> (and so on)
>
> in /var/log/foreman-proxy/proxy.log all I see is
>
> D, [2016-03-29T14:29:07.312002 #3483] DEBUG – : accept:
> 192.168.14.100:33703
> D, [2016-03-29T14:29:07.314182 #3483] DEBUG – : Rack::Handler::WEBrick is
> invoked.
> D, [2016-03-29T14:29:07.445111 #3483] DEBUG – : close: 192.168.14.100:33703
>
> and that's with log_level set to DEBUG in /etc/foreman-proxy/settings.yml
>
> /etc/salt/foreman.yaml
> —
> :proto: https
> :host: wellkatellodev.niwa.local
> :port: 443
> :ssl_ca: "/var/lib/puppet/ssl/certs/ca.pem"
> :ssl_cert: "/var/lib/puppet/ssl/private_keys/wellkatellodev.niwa.local.pem"
> :ssl_key: "/var/lib/puppet/ssl/certs/wellkatellodev.niwa.local.pem"
> :timeout: 10
> :salt: /usr/bin/salt
> :upload_grains: true
>
> /etc/foreman-proxy/settings.d/salt.yml
> —
> :enabled: true
> :autosign_file: /etc/salt/autosign.conf
> :salt_command_user: root
> # Some features require using the Salt API - such as listing
> # environments and retrieving state info
> :use_api: false

This needs to be true

··· ----- Original Message -----

:api_url: https://wellkatellodev.niwa.local:9000
:api_auth: ldap
:api_username: zsaltuser
:api_password: removed

My salt-api is configured in /etc/salt/master as below

Salt-API configuration

rest_cherrypy:
port: 9000
ssl_crt: /var/lib/puppet/ssl/certs/wellkatellodev.niwa.local.pem
ssl_key: /var/lib/puppet/ssl/private_keys/wellkatellodev.niwa.local.pem

with external auth configured

external_auth:
ldap:
zsaltuser:
- .*

and an LDAP connection to our directory server configured. I can run “salt
-a ldap ‘*’ test.ping” commands specifying zsaltuser fine, and I can use
curl to query the salt-api

Any help much appreciated! :slight_smile:

Dylan


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

Ahh bugger! Opps. I can now successfully import states, which then updated
the environments as well - BUT only after I added the '@runner' module to
the auth system

external_auth:
ldap:
zsaltuser:
- .*
- '@runner'

which come to think of it is specified in the docs "The user for the Smart
Proxy requires a minimum of the @runner permission."

Question - after the import the "hosts" associated with the the
environment/states are 0 in foreman - will foreman update this
automatically at some point given the configuration of the top.sls file?

Thanks for your help :slight_smile:
Dylan

··· On Wednesday, March 30, 2016 at 1:57:58 AM UTC+13, stephen wrote: > > > > > /etc/foreman-proxy/settings.d/salt.yml > > --- > > :enabled: true > > :autosign_file: /etc/salt/autosign.conf > > :salt_command_user: root > > # Some features require using the Salt API - such as listing > > # environments and retrieving state info > > :use_api: false > > > This needs to be true > > >

> From: "Dylan Baars" <baarsd@gmail.com>
> To: "Foreman users" <foreman-users@googlegroups.com>
> Cc: stephen@redhat.com
> Sent: Tuesday, March 29, 2016 1:42:56 PM
> Subject: Re: [foreman-users] Importing salt states fails ERF12-4701
>
> Ahh bugger! Opps. I can now successfully import states, which then updated
> the environments as well - BUT only after I added the '@runner' module to
> the auth system
>
> external_auth:
> ldap:
> zsaltuser:
> - .*
> - '@runner'
>
> which come to think of it is specified in the docs "The user for the Smart
> Proxy requires a minimum of the @runner permission."
>
> Question - after the import the "hosts" associated with the the
> environment/states are 0 in foreman - will foreman update this
> automatically at some point given the configuration of the top.sls file?

Ah, no - the two aren't connected like that. Foreman is just an input into the
tops system, so you can set the host's environment and add states in Foreman.

Top.sls is used alongside foreman, and whatever both specify is combined
together.

··· ----- Original Message -----

Thanks for your help :slight_smile:
Dylan

On Wednesday, March 30, 2016 at 1:57:58 AM UTC+13, stephen wrote:

/etc/foreman-proxy/settings.d/salt.yml

:enabled: true
:autosign_file: /etc/salt/autosign.conf
:salt_command_user: root

Some features require using the Salt API - such as listing

environments and retrieving state info

:use_api: false

This needs to be true


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

OK I'm not sure how it works then? I can create a new .sls file for my base
environment, (wget.sls), import it (via Configure > States), associate it
with a host (by editing the host - Hosts > All Hosts > select the host >
Edit > Salt states tab) and I can see by clicking "SALT ENC" that under
classes the state is listed, but if I do a "Run salt" the command that is
run on the minion is a state.highstate which only takes into account what
is in top.sls - so here's the salt ENC output

··· On Wednesday, March 30, 2016 at 7:05:03 AM UTC+13, stephen wrote: > > > > > > Question - after the import the "hosts" associated with the the > > environment/states are 0 in foreman - will foreman update this > > automatically at some point given the configuration of the top.sls file? > > Ah, no - the two aren't connected like that. Foreman is just an input into > the > tops system, so you can set the host's environment and add states in > Foreman. > > Top.sls is used alongside foreman, and whatever both specify is combined > together. >

classes:

  • wget
    parameters:
    puppetmaster: wellkatellodev.niwa.local
    organization: NIWA
    root_pw:
    puppet_ca: wellkatellodev.niwa.local
    foreman_env: production
    owner_name: Dylan Baars
    owner_email: removed
    foreman_subnets:
    foreman_interfaces:
    • mac: 00:50:56:85:14:ea
      ip: 192.168.14.102
      type: Interface
      name: wellminiondev.niwa.local
      attrs:
      netmask: 255.255.255.0
      mtu: ‘1500’
      network: 192.168.14.0
      virtual: false
      link: true
      identifier: eno16780032
      managed: true
      primary: true
      provision: true
      subnet:
      salt_master: wellkatellodev.niwa.local
      kt_env:
      kt_cv:
      lifecycle_environment:
      content_view:
      environment: base

This shows a “wget” class/state. But on the salt master top.sls -

base:
‘*’:
- editors
‘wellminiondev.niwa.local’:
- webserver

The “editors” and “webserver” salt states are applied, but not the ‘wget’
one. Here’s the minions log

2016-03-30 11:48:37,475 [salt.minion ][INFO ][2313] User
sudo_foreman-proxy Executing command state.highstate with jid
20160330114837466686
2016-03-30 11:48:37,495 [salt.minion ][INFO ][16527] Starting a new
job with PID 16527
2016-03-30 11:48:37,554 [salt.pillar ][INFO ][16527] Determining
pillar cache
2016-03-30 11:49:03,720 [salt.state ][INFO ][16527] Loading fresh
modules for state activity
2016-03-30 11:49:03,779 [salt.fileclient ][INFO ][16527] Fetching file
from saltenv ‘base’, ** done ** u’top.sls’
2016-03-30 11:49:29,975 [salt.loaded.int.module.saltutil][INFO ][16527]
Creating module dir ‘/var/cache/salt/minion/extmods/beacons’
2016-03-30 11:49:29,976 [salt.loaded.int.module.saltutil][INFO ][16527]
Syncing beacons for environment ‘base’
2016-03-30 11:49:29,977 [salt.loaded.int.module.saltutil][INFO ][16527]
Loading cache from salt://_beacons, for base)
2016-03-30 11:49:29,982 [salt.fileclient ][INFO ][16527] Caching
directory u’_beacons/’ for environment ‘base’
2016-03-30 11:49:29,988 [salt.loaded.int.module.saltutil][INFO ][16527]
Creating module dir ‘/var/cache/salt/minion/extmods/modules’
2016-03-30 11:49:29,989 [salt.loaded.int.module.saltutil][INFO ][16527]
Syncing modules for environment ‘base’
2016-03-30 11:49:29,989 [salt.loaded.int.module.saltutil][INFO ][16527]
Loading cache from salt://_modules, for base)
2016-03-30 11:49:29,990 [salt.fileclient ][INFO ][16527] Caching
directory u’_modules/’ for environment ‘base’
2016-03-30 11:49:29,995 [salt.loaded.int.module.saltutil][INFO ][16527]
Creating module dir ‘/var/cache/salt/minion/extmods/states’
2016-03-30 11:49:29,995 [salt.loaded.int.module.saltutil][INFO ][16527]
Syncing states for environment ‘base’
2016-03-30 11:49:29,996 [salt.loaded.int.module.saltutil][INFO ][16527]
Loading cache from salt://_states, for base)
2016-03-30 11:49:29,996 [salt.fileclient ][INFO ][16527] Caching
directory u’_states/’ for environment ‘base’
2016-03-30 11:49:30,001 [salt.loaded.int.module.saltutil][INFO ][16527]
Creating module dir ‘/var/cache/salt/minion/extmods/sdb’
2016-03-30 11:49:30,002 [salt.loaded.int.module.saltutil][INFO ][16527]
Syncing sdb for environment ‘base’
2016-03-30 11:49:30,002 [salt.loaded.int.module.saltutil][INFO ][16527]
Loading cache from salt://_sdb, for base)
2016-03-30 11:49:30,003 [salt.fileclient ][INFO ][16527] Caching
directory u’_sdb/’ for environment ‘base’
2016-03-30 11:49:30,009 [salt.loaded.int.module.saltutil][INFO ][16527]
Creating module dir ‘/var/cache/salt/minion/extmods/grains’
2016-03-30 11:49:30,010 [salt.loaded.int.module.saltutil][INFO ][16527]
Syncing grains for environment ‘base’
2016-03-30 11:49:30,011 [salt.loaded.int.module.saltutil][INFO ][16527]
Loading cache from salt://_grains, for base)
2016-03-30 11:49:30,011 [salt.fileclient ][INFO ][16527] Caching
directory u’_grains/’ for environment ‘base’
2016-03-30 11:49:30,020 [salt.loaded.int.module.saltutil][INFO ][16527]
Creating module dir ‘/var/cache/salt/minion/extmods/renderers’
2016-03-30 11:49:30,020 [salt.loaded.int.module.saltutil][INFO ][16527]
Syncing renderers for environment ‘base’
2016-03-30 11:49:30,021 [salt.loaded.int.module.saltutil][INFO ][16527]
Loading cache from salt://_renderers, for base)
2016-03-30 11:49:30,021 [salt.fileclient ][INFO ][16527] Caching
directory u’_renderers/’ for environment ‘base’
2016-03-30 11:49:30,026 [salt.loaded.int.module.saltutil][INFO ][16527]
Creating module dir ‘/var/cache/salt/minion/extmods/returners’
2016-03-30 11:49:30,026 [salt.loaded.int.module.saltutil][INFO ][16527]
Syncing returners for environment ‘base’
2016-03-30 11:49:30,027 [salt.loaded.int.module.saltutil][INFO ][16527]
Loading cache from salt://_returners, for base)
2016-03-30 11:49:30,027 [salt.fileclient ][INFO ][16527] Caching
directory u’_returners/’ for environment ‘base’
2016-03-30 11:49:30,032 [salt.loaded.int.module.saltutil][INFO ][16527]
Creating module dir ‘/var/cache/salt/minion/extmods/output’
2016-03-30 11:49:30,033 [salt.loaded.int.module.saltutil][INFO ][16527]
Syncing output for environment ‘base’
2016-03-30 11:49:30,033 [salt.loaded.int.module.saltutil][INFO ][16527]
Loading cache from salt://_output, for base)
2016-03-30 11:49:30,034 [salt.fileclient ][INFO ][16527] Caching
directory u’_output/’ for environment ‘base’
2016-03-30 11:49:30,040 [salt.loaded.int.module.saltutil][INFO ][16527]
Creating module dir ‘/var/cache/salt/minion/extmods/utils’
2016-03-30 11:49:30,040 [salt.loaded.int.module.saltutil][INFO ][16527]
Syncing utils for environment ‘base’
2016-03-30 11:49:30,041 [salt.loaded.int.module.saltutil][INFO ][16527]
Loading cache from salt://_utils, for base)
2016-03-30 11:49:30,041 [salt.fileclient ][INFO ][16527] Caching
directory u’utils/’ for environment ‘base’
2016-03-30 11:49:30,047 [salt.loaded.int.module.saltutil][INFO ][16527]
Creating module dir ‘/var/cache/salt/minion/extmods/log_handlers’
2016-03-30 11:49:30,047 [salt.loaded.int.module.saltutil][INFO ][16527]
Syncing log_handlers for environment ‘base’
2016-03-30 11:49:30,048 [salt.loaded.int.module.saltutil][INFO ][16527]
Loading cache from salt://log_handlers, for base)
2016-03-30 11:49:30,048 [salt.fileclient ][INFO ][16527] Caching
directory u’log_handlers/’ for environment ‘base’
2016-03-30 11:49:30,053 [salt.loaded.int.module.saltutil][INFO ][16527]
Creating module dir ‘/var/cache/salt/minion/extmods/proxy’
2016-03-30 11:49:30,054 [salt.loaded.int.module.saltutil][INFO ][16527]
Syncing proxy for environment ‘base’
2016-03-30 11:49:30,054 [salt.loaded.int.module.saltutil][INFO ][16527]
Loading cache from salt://proxy, for base)
2016-03-30 11:49:30,055 [salt.fileclient ][INFO ][16527] Caching
directory u’proxy/’ for environment ‘base’
2016-03-30 11:49:30,097 [salt.state ][INFO ][16527] Loading fresh
modules for state activity
2016-03-30 11:49:30,183 [salt.fileclient ][INFO ][16527] Fetching file
from saltenv ‘base’, ** done ** u’editors.sls’
2016-03-30 11:49:30,201 [salt.fileclient ][INFO ][16527] Fetching file
from saltenv ‘base’, ** done ** u’webserver.sls’
2016-03-30 11:49:30,460 [salt.loader ][ERROR ][16527] Exception
raised when processing virtual function for rh_service. Module will not
be loaded local variable ‘osrelease’ referenced before assignment
2016-03-30 11:49:30,460 [salt.loader ][WARNING ][16527]
salt.loaded.int.module.rh_service.virtual() is wrongly returning
None. It should either return True, False or a new name. If you’re
the developer of the module ‘rh_service’, please fix this.
2016-03-30 11:49:31,025 [salt.loader ][ERROR ][16527] Failed to
import module win_dacl, this is due most likely to a syntax error:
Traceback (most recent call last):
File “/usr/lib/python2.7/site-packages/salt/loader.py”, line 1136, in
load_module
), fn
, fpath, desc)
File “/usr/lib/python2.7/site-packages/salt/modules/win_dacl.py”, line
39, in
class daclConstants(object):
File “/usr/lib/python2.7/site-packages/salt/modules/win_dacl.py”, line
47, in daclConstants
FILE_ALL_ACCESS = (ntsecuritycon.STANDARD_RIGHTS_REQUIRED |
ntsecuritycon.SYNCHRONIZE | 0x1ff)
NameError: name ‘ntsecuritycon’ is not defined
2016-03-30 11:49:31,059 [salt.state ][INFO ][16527] Running state
[nano] at time 11:49:31.058546
2016-03-30 11:49:31,059 [salt.state ][INFO ][16527] Executing
state pkg.installed for nano
2016-03-30 11:49:31,060 [salt.loaded.int.module.cmdmod][INFO ][16527]
Executing command [‘rpm’, ‘-qa’, ‘–queryformat’,
'%{NAME}
|-%{EPOCH}
|-%{VERSION}
|-%{RELEASE}
|-%{ARCH}
|-(none)\n’] in
directory ‘/root’
2016-03-30 11:49:32,119 [salt.state ][INFO ][16527] Package nano
is already installed
2016-03-30 11:49:32,120 [salt.state ][INFO ][16527] Completed
state [nano] at time 11:49:32.119882
2016-03-30 11:49:32,120 [salt.state ][INFO ][16527] Running state
[httpd] at time 11:49:32.120221
2016-03-30 11:49:32,121 [salt.state ][INFO ][16527] Executing
state pkg.installed for httpd
2016-03-30 11:49:32,121 [salt.state ][INFO ][16527] Package httpd
is already installed
2016-03-30 11:49:32,121 [salt.state ][INFO ][16527] Completed
state [httpd] at time 11:49:32.121440
2016-03-30 11:49:32,122 [salt.minion ][INFO ][16527] Returning
information for job: 20160330114837466686

only the webserver.sls (which installs httpd) and the editors.sls (which
installs nano) are run, not the wget state

Is there something else I need to enable in my configuration?

Thanks for your help :slight_smile:

Dylan

And a follow up question - the upload of reports appears to be broken, in
/var/log/foreman-proxy/salt-cron.log I am getting

Traceback (most recent call last):
File "/usr/sbin/upload-salt-reports", line 137, in <module>
upload(jobs_to_upload())
File "/usr/sbin/upload-salt-reports", line 100, in upload
cert_file=config[':ssl_cert'])
File "/usr/lib64/python2.7/httplib.py", line 1182, in init
context.load_cert_chain(cert_file, key_file)
SSLError: [SSL] PEM lib (_ssl.c:2738)
Traceback (most recent call last):
File "/usr/sbin/upload-salt-reports", line 137, in <module>
upload(jobs_to_upload())
File "/usr/sbin/upload-salt-reports", line 100, in upload
cert_file=config[':ssl_cert'])
File "/usr/lib64/python2.7/httplib.py", line 1182, in init
context.load_cert_chain(cert_file, key_file)
SSLError: [SSL] PEM lib (_ssl.c:2738)

Any idea whats wrong here?

Thanks :slight_smile:
Dylan

Sorry for spamming. Fix this by matching the certificate files in
/etc/salt/foreman.yaml to the ones found in /etc/puppet/foreman.yaml

My /etc/salt/foreman.yaml now looks like

··· --- :proto: https :host: wellkatellodev.niwa.local :port: 443 :timeout: 10 :salt: /usr/bin/salt :upload_grains: true :ssl_ca: "/etc/puppet/ssl_ca.pem" :ssl_cert: "/etc/puppet/client_cert.pem" :ssl_key: "/etc/puppet/client_key.pem"

Dylan

On Wednesday, March 30, 2016 at 12:07:39 PM UTC+13, Dylan Baars wrote:

And a follow up question - the upload of reports appears to be broken, in
/var/log/foreman-proxy/salt-cron.log I am getting

Traceback (most recent call last):
File “/usr/sbin/upload-salt-reports”, line 137, in
upload(jobs_to_upload())
File “/usr/sbin/upload-salt-reports”, line 100, in upload
cert_file=config[‘:ssl_cert’])
File “/usr/lib64/python2.7/httplib.py”, line 1182, in init
context.load_cert_chain(cert_file, key_file)
SSLError: [SSL] PEM lib (_ssl.c:2738)
Traceback (most recent call last):
File “/usr/sbin/upload-salt-reports”, line 137, in
upload(jobs_to_upload())
File “/usr/sbin/upload-salt-reports”, line 100, in upload
cert_file=config[‘:ssl_cert’])
File “/usr/lib64/python2.7/httplib.py”, line 1182, in init
context.load_cert_chain(cert_file, key_file)
SSLError: [SSL] PEM lib (_ssl.c:2738)

Any idea whats wrong here?

Thanks :slight_smile:
Dylan

OK, re-reading the docs says

"Foreman provides an interface for adding Salt states to either a Foreman
host group or a host. Salt will know to apply these states through the
external node classification feature. This is done in addition to top.sls."

I assume that's this part in /etc/salt/master

master_tops:
ext_nodes: /usr/bin/foreman-node

so seems correct? However if I run that manually (assuming "foreman-node
salt-minion-name" is what it is attempting to do)

[root@wellkatellodev salt]# /usr/bin/foreman-node wellminiondev.niwa.local
Couldn't retrieve ENC data: execution expired

Back to it running via the foreman GUI "Run Salt" button - I see this in
the /var/log/salt/master logs

2016-03-30 17:48:44,649 [salt.utils.event ][DEBUG ][3301] Sending event -
data = {'_stamp': '2016-03-30T04:48:44.648530', 'minions':
['wellminiondev.niwa.local']}
2016-03-30 17:48:44,650 [salt.utils.event ][DEBUG ][3301] Sending event -
data = {'tgt_type': 'glob', 'jid': '20160330174844647917', 'tgt':
'wellminiondev.niwa.local', '_stamp': '2016-03-30T04:48:44.649605', 'user':
'sudo_foreman-proxy', 'arg': [], 'fun': 'state.highstate', 'minions':
['wellminiondev.niwa.local']}
2016-03-30 17:48:44,650 [salt.loaded.int.returner.local_cache][DEBUG
][3301] Adding minions for job 20160330174844647917:
['wellminiondev.niwa.local']
2016-03-30 17:48:44,651 [salt.master ][INFO ][3301] User
sudo_foreman-proxy Published command state.highstate with jid
20160330174844647917
2016-03-30 17:48:44,651 [salt.master ][DEBUG ][3301] Published
command details {'tgt_type': 'glob', 'jid': '20160330174844647917', 'tgt':
'wellminiondev.niwa.local', 'ret': '', 'user': 'sudo_foreman-proxy', 'arg':
[], 'fun': 'state.highstate'}
2016-03-30 17:48:44,760 [salt.pillar ][INFO ][3301] Determining
pillar cache
2016-03-30 17:48:44,778 [salt.utils.lazy ][DEBUG ][3301] LazyLoaded
jinja.render
2016-03-30 17:48:44,779 [salt.utils.lazy ][DEBUG ][3301] LazyLoaded
yaml.render
2016-03-30 17:48:44,781 [salt.utils.lazy ][DEBUG ][3301] LazyLoaded
puppet.ext_pillar
2016-03-30 17:48:44,783 [salt.utils.lazy ][DEBUG ][3301] LazyLoaded
cmd.run
2016-03-30 17:48:44,784 [salt.loaded.int.module.cmdmod][INFO ][3301]
Executing command '/usr/bin/foreman-node wellminiondev.niwa.local' in
directory '/root'
2016-03-30 17:49:10,840 [salt.loaded.int.module.cmdmod][ERROR ][3301]
Command '/usr/bin/foreman-node wellminiondev.niwa.local' failed with return
code: 1
2016-03-30 17:49:10,841 [salt.loaded.int.module.cmdmod][ERROR ][3301]
output: Couldn't retrieve ENC data: execution expired
2016-03-30 17:49:10,842 [salt.loaded.int.pillar.puppet][CRITICAL][3301]
YAML data from /usr/bin/foreman-node failed to parse
2016-03-30 17:49:19,730 [salt.loaded.int.returner.local_cache][DEBUG
][3296] Adding minions for job 20160330174919711612:
['wellkatellodev.niwa.local']
2016-03-30 17:49:19,731 [salt.utils.job ][INFO ][3296] Got return from
wellkatellodev.niwa.local for job 20160330174919711612
2016-03-30 17:49:19,731 [salt.utils.event ][DEBUG ][3296] Sending event -
data = {'tgt_type': 'glob', 'jid': '20160330174919711612', 'return': True,
'retcode': 0, 'success': True, 'schedule': 'mine_interval', 'tgt':
'wellkatellodev.niwa.local', 'cmd': 'return', 'pid': 21285, 'stamp':
'2016-03-30T04:49:19.730832', 'arg': [], 'fun': 'mine.update', 'id':
'wellkatellodev.niwa.local'}
2016-03-30 17:49:35,058 [salt.config ][DEBUG ][3289] Reading
configuration from /etc/salt/master
2016-03-30 17:49:35,157 [salt.config ][DEBUG ][3289] Including
configuration from '/etc/salt/minion.d/schedule.conf'
2016-03-30 17:49:35,157 [salt.config ][DEBUG ][3289] Reading
configuration from /etc/salt/minion.d/schedule.conf
2016-03-30 17:49:35,160 [salt.config ][DEBUG ][3289] Using cached
minion ID from /etc/salt/minion_id: wellkatellodev.niwa.local
2016-03-30 17:49:35,161 [salt.config ][DEBUG ][3289] Reading
configuration from /etc/salt/master
2016-03-30 17:49:37,010 [salt.loaded.int.top.ext_nodes][INFO ][3299]
master_tops ext_nodes call did not have a dictionary with a "classes" key.
2016-03-30 17:49:38,961 [salt.utils.job ][INFO ][3299] Got return from
wellminiondev.niwa.local for job 20160330174844647917
2016-03-30 17:49:38,962 [salt.utils.event ][DEBUG ][3299] Sending event -
data = {'fun_args': [], 'jid': '20160330174844647917', 'return':
{'pkg
|-httpd
|-httpd
|-installed': {'comment': 'Package httpd is already
installed', 'name': 'httpd', 'start_time': '17:49:38.853422', 'result':
True, 'duration': 1.439, 'run_num': 1, 'changes': {}},
'pkg
|-nano
|-nano
|-installed': {'comment': 'Package nano is already
installed', 'name': 'nano', 'start_time': '17:49:37.913413', 'result':
True, 'duration': 939.618, 'run_num': 0, 'changes': {}}}, 'retcode': 0,
'success': True, 'cmd': '_return', '_stamp': '2016-03-30T04:49:38.961428',
'fun': 'state.highstate', 'id': 'wellminiondev.niwa.local', 'out':
'highstate'}

Can I provide any more information? I see this issue here is
similar/same Bug #10692: foreman-salt reports errors while refreshing salt pillar data for minions - Salt - Foreman I don't have
foreman debug logging enabled to confirm whether I get the invalid IP in
the production.log file and have to leave work now, but interested to hear
what you think?

Thanks,
Dylan

··· On Wednesday, March 30, 2016 at 12:05:18 PM UTC+13, Dylan Baars wrote: > > On Wednesday, March 30, 2016 at 7:05:03 AM UTC+13, stephen wrote: >> >> >> > >> > Question - after the import the "hosts" associated with the the >> > environment/states are 0 in foreman - will foreman update this >> > automatically at some point given the configuration of the top.sls >> file? >> >> Ah, no - the two aren't connected like that. Foreman is just an input >> into the >> tops system, so you can set the host's environment and add states in >> Foreman. >> >> Top.sls is used alongside foreman, and whatever both specify is combined >> together. >> > > OK I'm not sure how it works then? I can create a new .sls file for my > base environment, (wget.sls), import it (via Configure > States), associate > it with a host (by editing the host - Hosts > All Hosts > select the host > > Edit > Salt states tab) and I can see by clicking "SALT ENC" that under > classes the state is listed, but if I do a "Run salt" the command that is > run on the minion is a state.highstate which only takes into account what > is in top.sls - so here's the salt ENC output > > --- > classes: > - wget > parameters: > puppetmaster: wellkatellodev.niwa.local > organization: NIWA > root_pw: > puppet_ca: wellkatellodev.niwa.local > foreman_env: production > owner_name: Dylan Baars > owner_email: removed > foreman_subnets: [] > foreman_interfaces: > - mac: 00:50:56:85:14:ea > ip: 192.168.14.102 > type: Interface > name: wellminiondev.niwa.local > attrs: > netmask: 255.255.255.0 > mtu: '1500' > network: 192.168.14.0 > virtual: false > link: true > identifier: eno16780032 > managed: true > primary: true > provision: true > subnet: > salt_master: wellkatellodev.niwa.local > kt_env: > kt_cv: > lifecycle_environment: > content_view: > environment: base > > >> > > This shows a "wget" class/state. But on the salt master top.sls - > > base: > '*': > - editors > 'wellminiondev.niwa.local': > - webserver > > The "editors" and "webserver" salt states are applied, but not the 'wget' > one. Here's the minions log > > 2016-03-30 11:48:37,475 [salt.minion ][INFO ][2313] User > sudo_foreman-proxy Executing command state.highstate with jid > 20160330114837466686 > 2016-03-30 11:48:37,495 [salt.minion ][INFO ][16527] Starting a > new job with PID 16527 > 2016-03-30 11:48:37,554 [salt.pillar ][INFO ][16527] Determining > pillar cache > 2016-03-30 11:49:03,720 [salt.state ][INFO ][16527] Loading fresh > modules for state activity > 2016-03-30 11:49:03,779 [salt.fileclient ][INFO ][16527] Fetching file > from saltenv 'base', ** done ** u'top.sls' > 2016-03-30 11:49:29,975 [salt.loaded.int.module.saltutil][INFO ][16527] > Creating module dir '/var/cache/salt/minion/extmods/beacons' > 2016-03-30 11:49:29,976 [salt.loaded.int.module.saltutil][INFO ][16527] > Syncing beacons for environment 'base' > 2016-03-30 11:49:29,977 [salt.loaded.int.module.saltutil][INFO ][16527] > Loading cache from salt://_beacons, for base) > 2016-03-30 11:49:29,982 [salt.fileclient ][INFO ][16527] Caching > directory u'_beacons/' for environment 'base' > 2016-03-30 11:49:29,988 [salt.loaded.int.module.saltutil][INFO ][16527] > Creating module dir '/var/cache/salt/minion/extmods/modules' > 2016-03-30 11:49:29,989 [salt.loaded.int.module.saltutil][INFO ][16527] > Syncing modules for environment 'base' > 2016-03-30 11:49:29,989 [salt.loaded.int.module.saltutil][INFO ][16527] > Loading cache from salt://_modules, for base) > 2016-03-30 11:49:29,990 [salt.fileclient ][INFO ][16527] Caching > directory u'_modules/' for environment 'base' > 2016-03-30 11:49:29,995 [salt.loaded.int.module.saltutil][INFO ][16527] > Creating module dir '/var/cache/salt/minion/extmods/states' > 2016-03-30 11:49:29,995 [salt.loaded.int.module.saltutil][INFO ][16527] > Syncing states for environment 'base' > 2016-03-30 11:49:29,996 [salt.loaded.int.module.saltutil][INFO ][16527] > Loading cache from salt://_states, for base) > 2016-03-30 11:49:29,996 [salt.fileclient ][INFO ][16527] Caching > directory u'_states/' for environment 'base' > 2016-03-30 11:49:30,001 [salt.loaded.int.module.saltutil][INFO ][16527] > Creating module dir '/var/cache/salt/minion/extmods/sdb' > 2016-03-30 11:49:30,002 [salt.loaded.int.module.saltutil][INFO ][16527] > Syncing sdb for environment 'base' > 2016-03-30 11:49:30,002 [salt.loaded.int.module.saltutil][INFO ][16527] > Loading cache from salt://_sdb, for base) > 2016-03-30 11:49:30,003 [salt.fileclient ][INFO ][16527] Caching > directory u'_sdb/' for environment 'base' > 2016-03-30 11:49:30,009 [salt.loaded.int.module.saltutil][INFO ][16527] > Creating module dir '/var/cache/salt/minion/extmods/grains' > 2016-03-30 11:49:30,010 [salt.loaded.int.module.saltutil][INFO ][16527] > Syncing grains for environment 'base' > 2016-03-30 11:49:30,011 [salt.loaded.int.module.saltutil][INFO ][16527] > Loading cache from salt://_grains, for base) > 2016-03-30 11:49:30,011 [salt.fileclient ][INFO ][16527] Caching > directory u'_grains/' for environment 'base' > 2016-03-30 11:49:30,020 [salt.loaded.int.module.saltutil][INFO ][16527] > Creating module dir '/var/cache/salt/minion/extmods/renderers' > 2016-03-30 11:49:30,020 [salt.loaded.int.module.saltutil][INFO ][16527] > Syncing renderers for environment 'base' > 2016-03-30 11:49:30,021 [salt.loaded.int.module.saltutil][INFO ][16527] > Loading cache from salt://_renderers, for base) > 2016-03-30 11:49:30,021 [salt.fileclient ][INFO ][16527] Caching > directory u'_renderers/' for environment 'base' > 2016-03-30 11:49:30,026 [salt.loaded.int.module.saltutil][INFO ][16527] > Creating module dir '/var/cache/salt/minion/extmods/returners' > 2016-03-30 11:49:30,026 [salt.loaded.int.module.saltutil][INFO ][16527] > Syncing returners for environment 'base' > 2016-03-30 11:49:30,027 [salt.loaded.int.module.saltutil][INFO ][16527] > Loading cache from salt://_returners, for base) > 2016-03-30 11:49:30,027 [salt.fileclient ][INFO ][16527] Caching > directory u'_returners/' for environment 'base' > 2016-03-30 11:49:30,032 [salt.loaded.int.module.saltutil][INFO ][16527] > Creating module dir '/var/cache/salt/minion/extmods/output' > 2016-03-30 11:49:30,033 [salt.loaded.int.module.saltutil][INFO ][16527] > Syncing output for environment 'base' > 2016-03-30 11:49:30,033 [salt.loaded.int.module.saltutil][INFO ][16527] > Loading cache from salt://_output, for base) > 2016-03-30 11:49:30,034 [salt.fileclient ][INFO ][16527] Caching > directory u'_output/' for environment 'base' > 2016-03-30 11:49:30,040 [salt.loaded.int.module.saltutil][INFO ][16527] > Creating module dir '/var/cache/salt/minion/extmods/utils' > 2016-03-30 11:49:30,040 [salt.loaded.int.module.saltutil][INFO ][16527] > Syncing utils for environment 'base' > 2016-03-30 11:49:30,041 [salt.loaded.int.module.saltutil][INFO ][16527] > Loading cache from salt://_utils, for base) > 2016-03-30 11:49:30,041 [salt.fileclient ][INFO ][16527] Caching > directory u'_utils/' for environment 'base' > 2016-03-30 11:49:30,047 [salt.loaded.int.module.saltutil][INFO ][16527] > Creating module dir '/var/cache/salt/minion/extmods/log_handlers' > 2016-03-30 11:49:30,047 [salt.loaded.int.module.saltutil][INFO ][16527] > Syncing log_handlers for environment 'base' > 2016-03-30 11:49:30,048 [salt.loaded.int.module.saltutil][INFO ][16527] > Loading cache from salt://_log_handlers, for base) > 2016-03-30 11:49:30,048 [salt.fileclient ][INFO ][16527] Caching > directory u'_log_handlers/' for environment 'base' > 2016-03-30 11:49:30,053 [salt.loaded.int.module.saltutil][INFO ][16527] > Creating module dir '/var/cache/salt/minion/extmods/proxy' > 2016-03-30 11:49:30,054 [salt.loaded.int.module.saltutil][INFO ][16527] > Syncing proxy for environment 'base' > 2016-03-30 11:49:30,054 [salt.loaded.int.module.saltutil][INFO ][16527] > Loading cache from salt://_proxy, for base) > 2016-03-30 11:49:30,055 [salt.fileclient ][INFO ][16527] Caching > directory u'_proxy/' for environment 'base' > 2016-03-30 11:49:30,097 [salt.state ][INFO ][16527] Loading fresh > modules for state activity > 2016-03-30 11:49:30,183 [salt.fileclient ][INFO ][16527] Fetching file > from saltenv 'base', ** done ** u'editors.sls' > 2016-03-30 11:49:30,201 [salt.fileclient ][INFO ][16527] Fetching file > from saltenv 'base', ** done ** u'webserver.sls' > 2016-03-30 11:49:30,460 [salt.loader ][ERROR ][16527] Exception > raised when processing __virtual__ function for rh_service. Module will not > be loaded local variable 'osrelease' referenced before assignment > 2016-03-30 11:49:30,460 [salt.loader ][WARNING ][16527] > salt.loaded.int.module.rh_service.__virtual__() is wrongly returning > `None`. It should either return `True`, `False` or a new name. If you're > the developer of the module 'rh_service', please fix this. > 2016-03-30 11:49:31,025 [salt.loader ][ERROR ][16527] Failed to > import module win_dacl, this is due most likely to a syntax error: > Traceback (most recent call last): > File "/usr/lib/python2.7/site-packages/salt/loader.py", line 1136, in > _load_module > ), fn_, fpath, desc) > File "/usr/lib/python2.7/site-packages/salt/modules/win_dacl.py", line > 39, in > class daclConstants(object): > File "/usr/lib/python2.7/site-packages/salt/modules/win_dacl.py", line > 47, in daclConstants > FILE_ALL_ACCESS = (ntsecuritycon.STANDARD_RIGHTS_REQUIRED | > ntsecuritycon.SYNCHRONIZE | 0x1ff) > NameError: name 'ntsecuritycon' is not defined > 2016-03-30 11:49:31,059 [salt.state ][INFO ][16527] Running state > [nano] at time 11:49:31.058546 > 2016-03-30 11:49:31,059 [salt.state ][INFO ][16527] Executing > state pkg.installed for nano > 2016-03-30 11:49:31,060 [salt.loaded.int.module.cmdmod][INFO ][16527] > Executing command ['rpm', '-qa', '--queryformat', > '%{NAME}_|-%{EPOCH}_|-%{VERSION}_|-%{RELEASE}_|-%{ARCH}_|-(none)\n'] in > directory '/root' > 2016-03-30 11:49:32,119 [salt.state ][INFO ][16527] Package nano > is already installed > 2016-03-30 11:49:32,120 [salt.state ][INFO ][16527] Completed > state [nano] at time 11:49:32.119882 > 2016-03-30 11:49:32,120 [salt.state ][INFO ][16527] Running state > [httpd] at time 11:49:32.120221 > 2016-03-30 11:49:32,121 [salt.state ][INFO ][16527] Executing > state pkg.installed for httpd > 2016-03-30 11:49:32,121 [salt.state ][INFO ][16527] Package httpd > is already installed > 2016-03-30 11:49:32,121 [salt.state ][INFO ][16527] Completed > state [httpd] at time 11:49:32.121440 > 2016-03-30 11:49:32,122 [salt.minion ][INFO ][16527] Returning > information for job: 20160330114837466686 > > only the webserver.sls (which installs httpd) and the editors.sls (which > installs nano) are run, not the wget state > > Is there something else I need to enable in my configuration? > > Thanks for your help :-) > > Dylan > > >

> From: "Dylan Baars" <baarsd@gmail.com>
> To: "Foreman users" <foreman-users@googlegroups.com>
> Cc: stephen@redhat.com
> Sent: Wednesday, March 30, 2016 12:54:53 AM
> Subject: Re: [foreman-users] Importing salt states fails ERF12-4701
>
> OK, re-reading the docs says
>
> "Foreman provides an interface for adding Salt states to either a Foreman
> host group or a host. Salt will know to apply these states through the
> external node classification feature. This is done in addition to top.sls."
>
> I assume that's this part in /etc/salt/master
>
> master_tops:
> ext_nodes: /usr/bin/foreman-node
>
> so seems correct? However if I run that manually (assuming "foreman-node
> salt-minion-name" is what it is attempting to do)
>
> [root@wellkatellodev salt]# /usr/bin/foreman-node wellminiondev.niwa.local
> Couldn't retrieve ENC data: execution expired

Did you start the foreman-tasks service on the foreman?

Can you provide the foreman production log?

··· ----- Original Message -----

Back to it running via the foreman GUI “Run Salt” button - I see this in
the /var/log/salt/master logs

2016-03-30 17:48:44,649 [salt.utils.event ][DEBUG ][3301] Sending event -
data = {‘_stamp’: ‘2016-03-30T04:48:44.648530’, ‘minions’:
[‘wellminiondev.niwa.local’]}
2016-03-30 17:48:44,650 [salt.utils.event ][DEBUG ][3301] Sending event -
data = {‘tgt_type’: ‘glob’, ‘jid’: ‘20160330174844647917’, ‘tgt’:
‘wellminiondev.niwa.local’, ‘_stamp’: ‘2016-03-30T04:48:44.649605’, ‘user’:
‘sudo_foreman-proxy’, ‘arg’: , ‘fun’: ‘state.highstate’, ‘minions’:
[‘wellminiondev.niwa.local’]}
2016-03-30 17:48:44,650 [salt.loaded.int.returner.local_cache][DEBUG
][3301] Adding minions for job 20160330174844647917:
[‘wellminiondev.niwa.local’]
2016-03-30 17:48:44,651 [salt.master ][INFO ][3301] User
sudo_foreman-proxy Published command state.highstate with jid
20160330174844647917
2016-03-30 17:48:44,651 [salt.master ][DEBUG ][3301] Published
command details {‘tgt_type’: ‘glob’, ‘jid’: ‘20160330174844647917’, ‘tgt’:
‘wellminiondev.niwa.local’, ‘ret’: ‘’, ‘user’: ‘sudo_foreman-proxy’, ‘arg’:
, ‘fun’: ‘state.highstate’}
2016-03-30 17:48:44,760 [salt.pillar ][INFO ][3301] Determining
pillar cache
2016-03-30 17:48:44,778 [salt.utils.lazy ][DEBUG ][3301] LazyLoaded
jinja.render
2016-03-30 17:48:44,779 [salt.utils.lazy ][DEBUG ][3301] LazyLoaded
yaml.render
2016-03-30 17:48:44,781 [salt.utils.lazy ][DEBUG ][3301] LazyLoaded
puppet.ext_pillar
2016-03-30 17:48:44,783 [salt.utils.lazy ][DEBUG ][3301] LazyLoaded
cmd.run
2016-03-30 17:48:44,784 [salt.loaded.int.module.cmdmod][INFO ][3301]
Executing command ‘/usr/bin/foreman-node wellminiondev.niwa.local’ in
directory ‘/root’
2016-03-30 17:49:10,840 [salt.loaded.int.module.cmdmod][ERROR ][3301]
Command ‘/usr/bin/foreman-node wellminiondev.niwa.local’ failed with return
code: 1
2016-03-30 17:49:10,841 [salt.loaded.int.module.cmdmod][ERROR ][3301]
output: Couldn’t retrieve ENC data: execution expired
2016-03-30 17:49:10,842 [salt.loaded.int.pillar.puppet][CRITICAL][3301]
YAML data from /usr/bin/foreman-node failed to parse
2016-03-30 17:49:19,730 [salt.loaded.int.returner.local_cache][DEBUG
][3296] Adding minions for job 20160330174919711612:
[‘wellkatellodev.niwa.local’]
2016-03-30 17:49:19,731 [salt.utils.job ][INFO ][3296] Got return from
wellkatellodev.niwa.local for job 20160330174919711612
2016-03-30 17:49:19,731 [salt.utils.event ][DEBUG ][3296] Sending event -
data = {‘tgt_type’: ‘glob’, ‘jid’: ‘20160330174919711612’, ‘return’: True,
‘retcode’: 0, ‘success’: True, ‘schedule’: ‘mine_interval’, ‘tgt’:
‘wellkatellodev.niwa.local’, ‘cmd’: 'return’, ‘pid’: 21285, ‘stamp’:
‘2016-03-30T04:49:19.730832’, ‘arg’: [], ‘fun’: ‘mine.update’, ‘id’:
‘wellkatellodev.niwa.local’}
2016-03-30 17:49:35,058 [salt.config ][DEBUG ][3289] Reading
configuration from /etc/salt/master
2016-03-30 17:49:35,157 [salt.config ][DEBUG ][3289] Including
configuration from '/etc/salt/minion.d/schedule.conf’
2016-03-30 17:49:35,157 [salt.config ][DEBUG ][3289] Reading
configuration from /etc/salt/minion.d/schedule.conf
2016-03-30 17:49:35,160 [salt.config ][DEBUG ][3289] Using cached
minion ID from /etc/salt/minion_id: wellkatellodev.niwa.local
2016-03-30 17:49:35,161 [salt.config ][DEBUG ][3289] Reading
configuration from /etc/salt/master
2016-03-30 17:49:37,010 [salt.loaded.int.top.ext_nodes][INFO ][3299]
master_tops ext_nodes call did not have a dictionary with a “classes” key.
2016-03-30 17:49:38,961 [salt.utils.job ][INFO ][3299] Got return from
wellminiondev.niwa.local for job 20160330174844647917
2016-03-30 17:49:38,962 [salt.utils.event ][DEBUG ][3299] Sending event -
data = {‘fun_args’: [], ‘jid’: ‘20160330174844647917’, ‘return’:
{'pkg
|-httpd
|-httpd
|-installed’: {‘comment’: ‘Package httpd is already
installed’, ‘name’: ‘httpd’, ‘start_time’: ‘17:49:38.853422’, ‘result’:
True, ‘duration’: 1.439, ‘run_num’: 1, ‘changes’: {}},
'pkg
|-nano
|-nano
|-installed’: {‘comment’: ‘Package nano is already
installed’, ‘name’: ‘nano’, ‘start_time’: ‘17:49:37.913413’, ‘result’:
True, ‘duration’: 939.618, ‘run_num’: 0, ‘changes’: {}}}, ‘retcode’: 0,
‘success’: True, ‘cmd’: ‘_return’, ‘_stamp’: ‘2016-03-30T04:49:38.961428’,
‘fun’: ‘state.highstate’, ‘id’: ‘wellminiondev.niwa.local’, ‘out’:
‘highstate’}

Can I provide any more information? I see this issue here is
similar/same Bug #10692: foreman-salt reports errors while refreshing salt pillar data for minions - Salt - Foreman I don’t have
foreman debug logging enabled to confirm whether I get the invalid IP in
the production.log file and have to leave work now, but interested to hear
what you think?

Thanks,
Dylan

On Wednesday, March 30, 2016 at 12:05:18 PM UTC+13, Dylan Baars wrote:

On Wednesday, March 30, 2016 at 7:05:03 AM UTC+13, stephen wrote:

Question - after the import the “hosts” associated with the the
environment/states are 0 in foreman - will foreman update this
automatically at some point given the configuration of the top.sls
file?

Ah, no - the two aren’t connected like that. Foreman is just an input
into the
tops system, so you can set the host’s environment and add states in
Foreman.

Top.sls is used alongside foreman, and whatever both specify is combined
together.

OK I’m not sure how it works then? I can create a new .sls file for my
base environment, (wget.sls), import it (via Configure > States), associate
it with a host (by editing the host - Hosts > All Hosts > select the host >
Edit > Salt states tab) and I can see by clicking “SALT ENC” that under
classes the state is listed, but if I do a “Run salt” the command that is
run on the minion is a state.highstate which only takes into account what
is in top.sls - so here’s the salt ENC output


classes:

  • wget
    parameters:
    puppetmaster: wellkatellodev.niwa.local
    organization: NIWA
    root_pw:
    puppet_ca: wellkatellodev.niwa.local
    foreman_env: production
    owner_name: Dylan Baars
    owner_email: removed
    foreman_subnets:
    foreman_interfaces:
    • mac: 00:50:56:85:14:ea
      ip: 192.168.14.102
      type: Interface
      name: wellminiondev.niwa.local
      attrs:
      netmask: 255.255.255.0
      mtu: ‘1500’
      network: 192.168.14.0
      virtual: false
      link: true
      identifier: eno16780032
      managed: true
      primary: true
      provision: true
      subnet:
      salt_master: wellkatellodev.niwa.local
      kt_env:
      kt_cv:
      lifecycle_environment:
      content_view:
      environment: base

This shows a “wget” class/state. But on the salt master top.sls -

base:
‘*’:
- editors
‘wellminiondev.niwa.local’:
- webserver

The “editors” and “webserver” salt states are applied, but not the ‘wget’
one. Here’s the minions log

2016-03-30 11:48:37,475 [salt.minion ][INFO ][2313] User
sudo_foreman-proxy Executing command state.highstate with jid
20160330114837466686
2016-03-30 11:48:37,495 [salt.minion ][INFO ][16527] Starting a
new job with PID 16527
2016-03-30 11:48:37,554 [salt.pillar ][INFO ][16527] Determining
pillar cache
2016-03-30 11:49:03,720 [salt.state ][INFO ][16527] Loading fresh
modules for state activity
2016-03-30 11:49:03,779 [salt.fileclient ][INFO ][16527] Fetching file
from saltenv ‘base’, ** done ** u’top.sls’
2016-03-30 11:49:29,975 [salt.loaded.int.module.saltutil][INFO ][16527]
Creating module dir ‘/var/cache/salt/minion/extmods/beacons’
2016-03-30 11:49:29,976 [salt.loaded.int.module.saltutil][INFO ][16527]
Syncing beacons for environment ‘base’
2016-03-30 11:49:29,977 [salt.loaded.int.module.saltutil][INFO ][16527]
Loading cache from salt://_beacons, for base)
2016-03-30 11:49:29,982 [salt.fileclient ][INFO ][16527] Caching
directory u’_beacons/’ for environment ‘base’
2016-03-30 11:49:29,988 [salt.loaded.int.module.saltutil][INFO ][16527]
Creating module dir ‘/var/cache/salt/minion/extmods/modules’
2016-03-30 11:49:29,989 [salt.loaded.int.module.saltutil][INFO ][16527]
Syncing modules for environment ‘base’
2016-03-30 11:49:29,989 [salt.loaded.int.module.saltutil][INFO ][16527]
Loading cache from salt://_modules, for base)
2016-03-30 11:49:29,990 [salt.fileclient ][INFO ][16527] Caching
directory u’_modules/’ for environment ‘base’
2016-03-30 11:49:29,995 [salt.loaded.int.module.saltutil][INFO ][16527]
Creating module dir ‘/var/cache/salt/minion/extmods/states’
2016-03-30 11:49:29,995 [salt.loaded.int.module.saltutil][INFO ][16527]
Syncing states for environment ‘base’
2016-03-30 11:49:29,996 [salt.loaded.int.module.saltutil][INFO ][16527]
Loading cache from salt://_states, for base)
2016-03-30 11:49:29,996 [salt.fileclient ][INFO ][16527] Caching
directory u’_states/’ for environment ‘base’
2016-03-30 11:49:30,001 [salt.loaded.int.module.saltutil][INFO ][16527]
Creating module dir ‘/var/cache/salt/minion/extmods/sdb’
2016-03-30 11:49:30,002 [salt.loaded.int.module.saltutil][INFO ][16527]
Syncing sdb for environment ‘base’
2016-03-30 11:49:30,002 [salt.loaded.int.module.saltutil][INFO ][16527]
Loading cache from salt://_sdb, for base)
2016-03-30 11:49:30,003 [salt.fileclient ][INFO ][16527] Caching
directory u’_sdb/’ for environment ‘base’
2016-03-30 11:49:30,009 [salt.loaded.int.module.saltutil][INFO ][16527]
Creating module dir ‘/var/cache/salt/minion/extmods/grains’
2016-03-30 11:49:30,010 [salt.loaded.int.module.saltutil][INFO ][16527]
Syncing grains for environment ‘base’
2016-03-30 11:49:30,011 [salt.loaded.int.module.saltutil][INFO ][16527]
Loading cache from salt://_grains, for base)
2016-03-30 11:49:30,011 [salt.fileclient ][INFO ][16527] Caching
directory u’_grains/’ for environment ‘base’
2016-03-30 11:49:30,020 [salt.loaded.int.module.saltutil][INFO ][16527]
Creating module dir ‘/var/cache/salt/minion/extmods/renderers’
2016-03-30 11:49:30,020 [salt.loaded.int.module.saltutil][INFO ][16527]
Syncing renderers for environment ‘base’
2016-03-30 11:49:30,021 [salt.loaded.int.module.saltutil][INFO ][16527]
Loading cache from salt://_renderers, for base)
2016-03-30 11:49:30,021 [salt.fileclient ][INFO ][16527] Caching
directory u’_renderers/’ for environment ‘base’
2016-03-30 11:49:30,026 [salt.loaded.int.module.saltutil][INFO ][16527]
Creating module dir ‘/var/cache/salt/minion/extmods/returners’
2016-03-30 11:49:30,026 [salt.loaded.int.module.saltutil][INFO ][16527]
Syncing returners for environment ‘base’
2016-03-30 11:49:30,027 [salt.loaded.int.module.saltutil][INFO ][16527]
Loading cache from salt://_returners, for base)
2016-03-30 11:49:30,027 [salt.fileclient ][INFO ][16527] Caching
directory u’_returners/’ for environment ‘base’
2016-03-30 11:49:30,032 [salt.loaded.int.module.saltutil][INFO ][16527]
Creating module dir ‘/var/cache/salt/minion/extmods/output’
2016-03-30 11:49:30,033 [salt.loaded.int.module.saltutil][INFO ][16527]
Syncing output for environment ‘base’
2016-03-30 11:49:30,033 [salt.loaded.int.module.saltutil][INFO ][16527]
Loading cache from salt://_output, for base)
2016-03-30 11:49:30,034 [salt.fileclient ][INFO ][16527] Caching
directory u’_output/’ for environment ‘base’
2016-03-30 11:49:30,040 [salt.loaded.int.module.saltutil][INFO ][16527]
Creating module dir ‘/var/cache/salt/minion/extmods/utils’
2016-03-30 11:49:30,040 [salt.loaded.int.module.saltutil][INFO ][16527]
Syncing utils for environment ‘base’
2016-03-30 11:49:30,041 [salt.loaded.int.module.saltutil][INFO ][16527]
Loading cache from salt://_utils, for base)
2016-03-30 11:49:30,041 [salt.fileclient ][INFO ][16527] Caching
directory u’utils/’ for environment ‘base’
2016-03-30 11:49:30,047 [salt.loaded.int.module.saltutil][INFO ][16527]
Creating module dir ‘/var/cache/salt/minion/extmods/log_handlers’
2016-03-30 11:49:30,047 [salt.loaded.int.module.saltutil][INFO ][16527]
Syncing log_handlers for environment ‘base’
2016-03-30 11:49:30,048 [salt.loaded.int.module.saltutil][INFO ][16527]
Loading cache from salt://log_handlers, for base)
2016-03-30 11:49:30,048 [salt.fileclient ][INFO ][16527] Caching
directory u’log_handlers/’ for environment ‘base’
2016-03-30 11:49:30,053 [salt.loaded.int.module.saltutil][INFO ][16527]
Creating module dir ‘/var/cache/salt/minion/extmods/proxy’
2016-03-30 11:49:30,054 [salt.loaded.int.module.saltutil][INFO ][16527]
Syncing proxy for environment ‘base’
2016-03-30 11:49:30,054 [salt.loaded.int.module.saltutil][INFO ][16527]
Loading cache from salt://proxy, for base)
2016-03-30 11:49:30,055 [salt.fileclient ][INFO ][16527] Caching
directory u’proxy/’ for environment ‘base’
2016-03-30 11:49:30,097 [salt.state ][INFO ][16527] Loading fresh
modules for state activity
2016-03-30 11:49:30,183 [salt.fileclient ][INFO ][16527] Fetching file
from saltenv ‘base’, ** done ** u’editors.sls’
2016-03-30 11:49:30,201 [salt.fileclient ][INFO ][16527] Fetching file
from saltenv ‘base’, ** done ** u’webserver.sls’
2016-03-30 11:49:30,460 [salt.loader ][ERROR ][16527] Exception
raised when processing virtual function for rh_service. Module will not
be loaded local variable ‘osrelease’ referenced before assignment
2016-03-30 11:49:30,460 [salt.loader ][WARNING ][16527]
salt.loaded.int.module.rh_service.virtual() is wrongly returning
None. It should either return True, False or a new name. If you’re
the developer of the module ‘rh_service’, please fix this.
2016-03-30 11:49:31,025 [salt.loader ][ERROR ][16527] Failed to
import module win_dacl, this is due most likely to a syntax error:
Traceback (most recent call last):
File “/usr/lib/python2.7/site-packages/salt/loader.py”, line 1136, in
load_module
), fn
, fpath, desc)
File “/usr/lib/python2.7/site-packages/salt/modules/win_dacl.py”, line
39, in
class daclConstants(object):
File “/usr/lib/python2.7/site-packages/salt/modules/win_dacl.py”, line
47, in daclConstants
FILE_ALL_ACCESS = (ntsecuritycon.STANDARD_RIGHTS_REQUIRED |
ntsecuritycon.SYNCHRONIZE | 0x1ff)
NameError: name ‘ntsecuritycon’ is not defined
2016-03-30 11:49:31,059 [salt.state ][INFO ][16527] Running state
[nano] at time 11:49:31.058546
2016-03-30 11:49:31,059 [salt.state ][INFO ][16527] Executing
state pkg.installed for nano
2016-03-30 11:49:31,060 [salt.loaded.int.module.cmdmod][INFO ][16527]
Executing command [‘rpm’, ‘-qa’, ‘–queryformat’,
'%{NAME}
|-%{EPOCH}
|-%{VERSION}
|-%{RELEASE}
|-%{ARCH}
|-(none)\n’] in
directory ‘/root’
2016-03-30 11:49:32,119 [salt.state ][INFO ][16527] Package nano
is already installed
2016-03-30 11:49:32,120 [salt.state ][INFO ][16527] Completed
state [nano] at time 11:49:32.119882
2016-03-30 11:49:32,120 [salt.state ][INFO ][16527] Running state
[httpd] at time 11:49:32.120221
2016-03-30 11:49:32,121 [salt.state ][INFO ][16527] Executing
state pkg.installed for httpd
2016-03-30 11:49:32,121 [salt.state ][INFO ][16527] Package httpd
is already installed
2016-03-30 11:49:32,121 [salt.state ][INFO ][16527] Completed
state [httpd] at time 11:49:32.121440
2016-03-30 11:49:32,122 [salt.minion ][INFO ][16527] Returning
information for job: 20160330114837466686

only the webserver.sls (which installs httpd) and the editors.sls (which
installs nano) are run, not the wget state

Is there something else I need to enable in my configuration?

Thanks for your help :slight_smile:

Dylan


You received this message because you are subscribed to the Google Groups
“Foreman users” group.
To unsubscribe from this group and stop receiv

Morning,

with debug logging for foreman enabled - edited /etc/foreman/settings.yaml

:logging:

:level: info

:level: debug

this is what is output when I hit "Run Salt" in the GUI

> Started GET "/salt/run/wellminiondev.niwa.local" for 192.168.81.51 at
2016-03-31 06:30:45 +1300
2016-03-31 06:30:45 [app] [I] Processing by
ForemanSalt::MinionsController#run as HTML
2016-03-31 06:30:45 [app] [I] Parameters:
{"id"=>"wellminiondev.niwa.local"}
2016-03-31 06:30:45 [app] [D] Setting current user thread-local variable to
Dylan Baars
2016-03-31 06:30:45 [app] [D] Setting current organization thread-local
variable to NIWA
2016-03-31 06:30:45 [app] [D] Setting current location thread-local
variable to none
2016-03-31 06:30:47 [app] [I] Redirected to
https://wellkatellodev.niwa.local/hosts/wellminiondev.niwa.local
2016-03-31 06:30:47 [app] [I] Completed 302 Found in 1288ms (ActiveRecord:
16.9ms)
2016-03-31 06:30:47 [app] [I]
>
> Started GET "/hosts/wellminiondev.niwa.local" for 192.168.81.51 at
2016-03-31 06:30:47 +1300
2016-03-31 06:30:47 [app] [I] Processing by HostsController#show as HTML
2016-03-31 06:30:47 [app] [I] Parameters:
{"id"=>"wellminiondev.niwa.local"}
2016-03-31 06:30:47 [app] [D] Setting current user thread-local variable to
Dylan Baars
2016-03-31 06:30:47 [app] [D] Setting current organization thread-local
variable to NIWA
2016-03-31 06:30:47 [app] [D] Setting current location thread-local
variable to none
2016-03-31 06:30:47 [app] [D] Deface: 1 overrides found for 'hosts/show'
2016-03-31 06:30:47 [app] [D] Deface: 'add_system_link_to_host' matched 1
times with 'td:first'
2016-03-31 06:30:47 [app] [I] Deface: [WARNING] No :original defined for
'add_system_link_to_host', you should change its definition to include:
> :original => '68201d5314be8a5aeb05b063bc5cd0afaf58a6c5'
2016-03-31 06:30:48 [app] [I] Rendered hosts/metrics.html.erb (1.2ms)
2016-03-31 06:30:48 [app] [I] Rendered hosts/show.html.erb within
layouts/application (948.3ms)
2016-03-31 06:30:48 [app] [I] Rendered home/user_dropdown.html.erb
(239.2ms)
2016-03-31 06:30:48 [app] [I] Read fragment views/tabs_and_title_records-4
(0.3ms)
2016-03-31 06:30:48 [app] [I] Rendered home/topbar.html.erb (242.4ms)
2016-03-31 06:30:48 [app] [I] Rendered layouts/base.html.erb (246.2ms)
2016-03-31 06:30:48 [app] [I] Completed 200 OK in 1557ms (Views: 1416.4ms |
ActiveRecord: 27.6ms)
2016-03-31 06:30:49 [app] [I]
>
> Started GET "/hosts/wellminiondev.niwa.local/overview" for 192.168.81.51
at 2016-03-31 06:30:49 +1300
2016-03-31 06:30:49 [app] [I] Processing by HostsController#overview as HTML
2016-03-31 06:30:49 [app] [I] Parameters:
{"id"=>"wellminiondev.niwa.local"}
2016-03-31 06:30:49 [app] [D] Setting current user thread-local variable to
Dylan Baars
2016-03-31 06:30:49 [app] [D] Setting current organization thread-local
variable to NIWA
2016-03-31 06:30:49 [app] [D] Setting current location thread-local
variable to none
2016-03-31 06:30:49 [app] [I]
>
> Started GET "/hosts/wellminiondev.niwa.local/nics" for 192.168.81.51 at
2016-03-31 06:30:49 +1300
2016-03-31 06:30:49 [app] [D] Deface: 1 overrides found for
'hosts/overview'
2016-03-31 06:30:49 [app] [D] Deface: 'add_system_status_to_host' matched 1
times with 'tr:first-child'
2016-03-31 06:30:49 [app] [I] Deface: [WARNING] No :original defined for
'add_system_status_to_host', you should change its definition to include:
> :original => '68e6b32c550fbc7beca04e60b2851003b1f3afed'
2016-03-31 06:30:49 [app] [I] Processing by HostsController#nics as HTML
2016-03-31 06:30:49 [app] [I] Parameters:
{"id"=>"wellminiondev.niwa.local"}
2016-03-31 06:30:49 [app] [I]
>
> Started GET "/hosts/wellminiondev.niwa.local/resources?range=7" for
192.168.81.51 at 2016-03-31 06:30:49 +1300
2016-03-31 06:30:49 [app] [D] Setting current user thread-local variable to
Dylan Baars
2016-03-31 06:30:49 [app] [I]
>
> Started GET "/hosts/wellminiondev.niwa.local/runtime?range=7" for
192.168.81.51 at 2016-03-31 06:30:49 +1300
2016-03-31 06:30:49 [app] [D] Setting current organization thread-local
variable to NIWA
2016-03-31 06:30:49 [app] [D] Setting current location thread-local
variable to none
2016-03-31 06:30:49 [app] [I] Processing by HostsController#runtime as HTML
2016-03-31 06:30:49 [app] [I] Parameters: {"range"=>"7",
"id"=>"wellminiondev.niwa.local"}
2016-03-31 06:30:49 [app] [I] Processing by HostsController#resources as
HTML
2016-03-31 06:30:49 [app] [I] Parameters: {"range"=>"7",
"id"=>"wellminiondev.niwa.local"}
2016-03-31 06:30:49 [app] [D] Setting current user thread-local variable to
Dylan Baars
2016-03-31 06:30:49 [app] [D] Setting current user thread-local variable to
Dylan Baars
2016-03-31 06:30:49 [app] [D] Setting current organization thread-local
variable to NIWA
2016-03-31 06:30:49 [app] [D] Setting current location thread-local
variable to none
2016-03-31 06:30:49 [app] [I] Rendered hosts/nics.html.erb (20.0ms)
2016-03-31 06:30:49 [app] [I] Completed 200 OK in 69ms (Views: 11.3ms |
ActiveRecord: 36.6ms)
2016-03-31 06:30:49 [app] [D] Setting current organization thread-local
variable to NIWA
2016-03-31 06:30:49 [app] [D] Setting current location thread-local
variable to none
2016-03-31 06:30:49 [app] [I]
>
> Started GET "/hosts/wellminiondev.niwa.local/templates" for
192.168.81.51 at 2016-03-31 06:30:49 +1300
2016-03-31 06:30:50 [app] [I] Rendered hosts/resources.html.erb (320.1ms)
2016-03-31 06:30:50 [app] [I] Completed 200 OK in 755ms (Views: 714.7ms |
ActiveRecord: 19.3ms)
2016-03-31 06:30:50 [app] [I] Rendered hosts/overview.html.erb (931.7ms)
2016-03-31 06:30:50 [app] [I] Completed 200 OK in 974ms (Views: 744.6ms |
ActiveRecord: 204.4ms)
2016-03-31 06:30:50 [app] [I] Rendered hosts/runtime.html.erb (1339.7ms)
2016-03-31 06:30:50 [app] [I] Completed 200 OK in 1415ms (Views: 874.3ms |
ActiveRecord: 511.4ms)
2016-03-31 06:30:51 [app] [I] Processing by HostsController#templates as
HTML
2016-03-31 06:30:51 [app] [I] Parameters:
{"id"=>"wellminiondev.niwa.local"}
2016-03-31 06:30:51 [app] [D] Setting current user thread-local variable to
Dylan Baars
2016-03-31 06:30:51 [app] [D] Setting current organization thread-local
variable to NIWA
2016-03-31 06:30:51 [app] [D] Setting current location thread-local
variable to none
2016-03-31 06:30:52 [app] [I] Rendered text template (0.0ms)
2016-03-31 06:30:52 [app] [I] Completed 200 OK in 1767ms (Views: 257.3ms |
ActiveRecord: 21.3ms)
2016-03-31 06:30:53 [foreman-tasks/dynflow] [I] start terminating
throttle_limiter…
2016-03-31 06:30:53 [foreman-tasks/dynflow] [I] start terminating client
dispatcher…
2016-03-31 06:30:53 [foreman-tasks/dynflow] [I] stop listening for new
events…
2016-03-31 06:30:53 [foreman-tasks/dynflow] [I] start terminating clock…
2016-03-31 06:30:54 [foreman-tasks/dynflow] [I] start terminating
throttle_limiter…
2016-03-31 06:30:54 [foreman-tasks/dynflow] [I] start terminating client
dispatcher…
2016-03-31 06:30:54 [foreman-tasks/dynflow] [I] stop listening for new
events…
2016-03-31 06:30:54 [foreman-tasks/dynflow] [I] start terminating clock…
2016-03-31 06:32:10 [app] [I]
>
> Started POST "/salt/api/v2/jobs/upload" for 192.168.14.100 at 2016-03-31
06:32:10 +1300
2016-03-31 06:32:10 [app] [I] Processing by
ForemanSalt::Api::V2::JobsController#upload as JSON
2016-03-31 06:32:10 [app] [I] Parameters:
{"job"=>{"function"=>"state.highstate",
"result"=>{"wellminiondev.niwa.local"=>{"pkg
|-httpd
|-httpd
|-installed"=>{"comment"=>"Package
httpd is already installed", "name"=>"httpd",
"start_time"=>"06:31:42.106300", "result"=>true, "duration"=>2.279,
"run_num"=>1, "changes"=>{}},
"pkg
|-nano
|-nano
|-installed"=>{"comment"=>"Package nano is already
installed", "name"=>"nano", "start_time"=>"06:31:41.098023",
"result"=>true, "duration"=>1007.931, "run_num"=>0, "changes"=>{}}}},
"job_id"=>"20160331063047033123"}, "apiv"=>"v2"}
2016-03-31 06:32:10 [app] [D] Verifying request from
["wellkatellodev.niwa.local"] against ["wellkatellodev.niwa.local"]
2016-03-31 06:32:10 [app] [D] Setting current user thread-local variable to
API Admin
2016-03-31 06:32:10 [app] [I] Processing job 20160331063047033123 from Salt.
2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] ExecutionPlan
41e4ddb7-8ea1-496a-a91c-8ac41af03ba6 pending >> planning
2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] Step
41e4ddb7-8ea1-496a-a91c-8ac41af03ba6: 1 pending >> running in phase
Plan Actions::ForemanSalt::ReportImport
2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] Step
41e4ddb7-8ea1-496a-a91c-8ac41af03ba6: 1 running >> success in phase
Plan Actions::ForemanSalt::ReportImport
2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] ExecutionPlan
41e4ddb7-8ea1-496a-a91c-8ac41af03ba6 planning >> planned
2016-03-31 06:32:11 [app] [D] Body:
{"task_id":"45e6aae0-a06b-4199-b27b-901e864ea244"}
2016-03-31 06:32:11 [app] [I] Completed 200 OK in 910ms (Views: 0.4ms |
ActiveRecord: 282.6ms)
2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] ExecutionPlan
41e4ddb7-8ea1-496a-a91c-8ac41af03ba6 planned >> running
2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] Step
41e4ddb7-8ea1-496a-a91c-8ac41af03ba6: 2 pending >> running in phase
Run Actions::ForemanSalt::ReportImport
2016-03-31 06:32:11 [app] [D] Setting current user thread-local variable to
Anonymous Admin
2016-03-31 06:32:12 [app] [I] processing report for wellminiondev.niwa.local
2016-03-31 06:32:12 [app] [D] Report:
{"pkg
|-httpd
|-httpd_|-installed"=>{"comment"=>"Package httpd is already
installed", "name"=>"httpd", "start_time"=>"06:31:42.106300",
"result"=>true, "duration"=>2.279, "run_num"=>1, "changes"=>{}},
"pkg_|-nano_|-nano_|-installed"=>{"comment"=>"Package nano is already
installed", "name"=>"nano", "start_time"=>"06:31:41.098023",
"result"=>true, "duration"=>1007.931, "run_num"=>0, "changes"=>{}}}
2016-03-31 06:32:13 [app] [I] Imported report for wellminiondev.niwa.local
in 0.77 seconds
2016-03-31 06:32:13 [foreman-tasks/dynflow] [D] Step
41e4ddb7-8ea1-496a-a91c-8ac41af03ba6: 2 running >> success in phase
Run Actions::ForemanSalt::ReportImport
2016-03-31 06:32:13 [foreman-tasks/dynflow] [D] ExecutionPlan
41e4ddb7-8ea1-496a-a91c-8ac41af03ba6 running >> stopped

and here's the /var/log/salt/master output for the same command

2016-03-31 06:30:47,174 [salt.loaded.int.module.cmdmod][INFO ][3294]
Executing command '/usr/bin/foreman-node wellminiondev.niwa.local' in
directory '/root'
2016-03-31 06:31:13,591 [salt.loaded.int.module.cmdmod][ERROR ][3294]
Command '/usr/bin/foreman-node wellminiondev.niwa.local' failed with return
code: 1
2016-03-31 06:31:13,594 [salt.loaded.int.module.cmdmod][ERROR ][3294]
output: Couldn't retrieve ENC data: execution expired
2016-03-31 06:31:13,596 [salt.loaded.int.pillar.puppet][CRITICAL][3294]
YAML data from /usr/bin/foreman-node failed to parse
2016-03-31 06:31:13,660 [salt.utils.lazy ][DEBUG ][3292] LazyLoaded
roots.envs
2016-03-31 06:31:40,102 [salt.loaded.int.top.ext_nodes][INFO ][3295]
master_tops ext_nodes call did not have a dictionary with a "classes" key.
2016-03-31 06:31:41,689 [salt.config ][DEBUG ][3288] Reading
configuration from /etc/salt/master
2016-03-31 06:31:41,847 [salt.config ][DEBUG ][3288] Including
configuration from '/etc/salt/minion.d/schedule.conf'
2016-03-31 06:31:41,847 [salt.config ][DEBUG ][3288] Reading
configuration from /etc/salt/minion.d/schedule.conf
2016-03-31 06:31:41,851 [salt.config ][DEBUG ][3288] Using cached
minion ID from /etc/salt/minion_id: wellkatellodev.niwa.local
2016-03-31 06:31:41,853 [salt.config ][DEBUG ][3288] Reading
configuration from /etc/salt/master
2016-03-31 06:31:42,215 [salt.utils.job ][INFO ][3291] Got return from
wellminiondev.niwa.local for job 20160331063047033123
2016-03-31 06:31:42,215 [salt.utils.event ][DEBUG ][3291] Sending event -
data = {'fun_args': [], 'jid': '20160331063047033123', 'return':
{'pkg
|-httpd
|-httpd_|-installed': {'comment': 'Package httpd is already
installed', 'name': 'httpd', 'start_time': '06:31:42.106300', 'result':
True, 'duration': 2.279, 'run_num': 1, 'changes': {}},
'pkg_|-nano_|-nano_|-installed': {'comment': 'Package nano is already
installed', 'name': 'nano', 'start_time': '06:31:41.098023', 'result':
True, 'duration': 1007.931, 'run_num': 0, 'changes': {}}}, 'retcode':
0, 'success': True, 'cmd': '_return', '_stamp':
'2016-03-30T17:31:42.215041', 'fun': 'state.highstate', 'id':
'wellminiondev.niwa.local', 'out': 'highstate'}
2016-03-31 06:32:07,306 [salt.utils.lazy ][DEBUG ][3288] LazyLoaded
local_cache.clean_old_jobs
2016-03-31 06:32:07,319 [salt.utils.lazy ][DEBUG ][3288] Could not
LazyLoad config.merge
2016-03-31 06:32:07,320 [salt.fileserver ][DEBUG ][3288] Updating roots
fileserver cache
2016-03-31 06:32:07,321 [salt.utils.verify][DEBUG ][3288] This
salt-master instance has accepted 2 minion keys.
2016-03-31 06:33:07,371 [salt.config ][DEBUG ][3288] Reading
configuration from /etc/salt/master
2016-03-31 06:33:07,468 [salt.config ][DEBUG ][3288] Including
configuration from '/etc/salt/minion.d/_schedule.conf'
2016-03-31 06:33:07,469 [salt.config ][DEBUG ][3288] Reading
configuration from /etc/salt/minion.d/_schedule.conf
2016-03-31 06:33:07,471 [salt.config ][DEBUG ][3288] Using cached
minion ID from /etc/salt/minion_id: wellkatellodev.niwa.local
2016-03-31 06:33:07,473 [salt.config ][DEBUG ][3288] Reading
configuration from /etc/salt/master

Foreman-tasks service is running

[root@wellkatellodev ~]# systemctl status foreman-tasks
● foreman-tasks.service - Foreman jobs daemon
Loaded: loaded (/usr/lib/systemd/system/foreman-tasks.service; enabled;
vendor preset: disabled)
Active: active (running) since Thu 2016-03-31 06:27:47 NZDT; 7min ago
Docs: https://github.com/theforeman/foreman-tasks
Process: 1651 ExecStart=/usr/bin/foreman-tasks start (code=exited,
status=0/SUCCESS)
CGroup: /system.slice/foreman-tasks.service
├─3656 dynflow_executor
└─3662 dynflow_executor_monitor

Mar 31 06:27:16 wellkatellodev.niwa.local systemd[1]: Starting Foreman jobs
daemon…
Mar 31 06:27:46 wellkatellodev.niwa.local foreman-tasks[1651]: Dynflow
Executor: start in progress
Mar 31 06:27:47 wellkatellodev.niwa.local foreman-tasks[1651]:
dynflow_executor: process with pid 3656 started.
Mar 31 06:27:47 wellkatellodev.niwa.local systemd[1]: Started Foreman jobs
daemon.

Thanks again for your help, it's much appreciated!
Dylan

··· On Thursday, March 31, 2016 at 12:08:30 AM UTC+13, stephen wrote: > > > > ----- Original Message ----- > > From: "Dylan Baars" <baa...@gmail.com > > > To: "Foreman users" <forema...@googlegroups.com > > > Cc: ste...@redhat.com > > Sent: Wednesday, March 30, 2016 12:54:53 AM > > Subject: Re: [foreman-users] Importing salt states fails ERF12-4701 > > > > OK, re-reading the docs says > > > > "Foreman provides an interface for adding Salt states to either a > Foreman > > host group or a host. Salt will know to apply these states through the > > external node classification feature. This is done in addition to > top.sls." > > > > I assume that's this part in /etc/salt/master > > > > master_tops: > > ext_nodes: /usr/bin/foreman-node > > > > so seems correct? However if I run that manually (assuming "foreman-node > > salt-minion-name" is what it is attempting to do) > > > > [root@wellkatellodev salt]# /usr/bin/foreman-node > wellminiondev.niwa.local > > Couldn't retrieve ENC data: execution expired > > > Did you start the foreman-tasks service on the foreman? > > > Can you provide the foreman production log? > > > Back to it running via the foreman GUI "Run Salt" button - I see this in > > the /var/log/salt/master logs > > > > 2016-03-30 17:48:44,649 [salt.utils.event ][DEBUG ][3301] Sending > event - > > data = {'_stamp': '2016-03-30T04:48:44.648530', 'minions': > > ['wellminiondev.niwa.local']} > > 2016-03-30 17:48:44,650 [salt.utils.event ][DEBUG ][3301] Sending > event - > > data = {'tgt_type': 'glob', 'jid': '20160330174844647917', 'tgt': > > 'wellminiondev.niwa.local', '_stamp': '2016-03-30T04:48:44.649605', > 'user': > > 'sudo_foreman-proxy', 'arg': [], 'fun': 'state.highstate', 'minions': > > ['wellminiondev.niwa.local']} > > 2016-03-30 17:48:44,650 [salt.loaded.int.returner.local_cache][DEBUG > > ][3301] Adding minions for job 20160330174844647917: > > ['wellminiondev.niwa.local'] > > 2016-03-30 17:48:44,651 [salt.master ][INFO ][3301] User > > sudo_foreman-proxy Published command state.highstate with jid > > 20160330174844647917 > > 2016-03-30 17:48:44,651 [salt.master ][DEBUG ][3301] Published > > command details {'tgt_type': 'glob', 'jid': '20160330174844647917', > 'tgt': > > 'wellminiondev.niwa.local', 'ret': '', 'user': 'sudo_foreman-proxy', > 'arg': > > [], 'fun': 'state.highstate'} > > 2016-03-30 17:48:44,760 [salt.pillar ][INFO ][3301] Determining > > pillar cache > > 2016-03-30 17:48:44,778 [salt.utils.lazy ][DEBUG ][3301] LazyLoaded > > jinja.render > > 2016-03-30 17:48:44,779 [salt.utils.lazy ][DEBUG ][3301] LazyLoaded > > yaml.render > > 2016-03-30 17:48:44,781 [salt.utils.lazy ][DEBUG ][3301] LazyLoaded > > puppet.ext_pillar > > 2016-03-30 17:48:44,783 [salt.utils.lazy ][DEBUG ][3301] LazyLoaded > > cmd.run > > 2016-03-30 17:48:44,784 [salt.loaded.int.module.cmdmod][INFO ][3301] > > Executing command '/usr/bin/foreman-node wellminiondev.niwa.local' in > > directory '/root' > > 2016-03-30 17:49:10,840 [salt.loaded.int.module.cmdmod][ERROR ][3301] > > Command '/usr/bin/foreman-node wellminiondev.niwa.local' failed with > return > > code: 1 > > 2016-03-30 17:49:10,841 [salt.loaded.int.module.cmdmod][ERROR ][3301] > > output: Couldn't retrieve ENC data: execution expired > > 2016-03-30 17:49:10,842

I don't see any errors here, it looks like Salt ran successfully, and even uploaded a report to Foreman.

Can you run foreman-node fqdn like in your other message, and share the production.log if you still get an error?

··· ----- Original Message ----- > From: "Dylan Baars" > To: "Foreman users" > Cc: stephen@redhat.com > Sent: Wednesday, March 30, 2016 1:40:58 PM > Subject: Re: [foreman-users] Importing salt states fails ERF12-4701 > > Morning, > > with debug logging for foreman enabled - edited /etc/foreman/settings.yaml > > :logging: > # :level: info > :level: debug > > > this is what is output when I hit "Run Salt" in the GUI > > > Started GET "/salt/run/wellminiondev.niwa.local" for 192.168.81.51 at > 2016-03-31 06:30:45 +1300 > 2016-03-31 06:30:45 [app] [I] Processing by > ForemanSalt::MinionsController#run as HTML > 2016-03-31 06:30:45 [app] [I] Parameters: > {"id"=>"wellminiondev.niwa.local"} > 2016-03-31 06:30:45 [app] [D] Setting current user thread-local variable to > Dylan Baars > 2016-03-31 06:30:45 [app] [D] Setting current organization thread-local > variable to NIWA > 2016-03-31 06:30:45 [app] [D] Setting current location thread-local > variable to none > 2016-03-31 06:30:47 [app] [I] Redirected to > https://wellkatellodev.niwa.local/hosts/wellminiondev.niwa.local > 2016-03-31 06:30:47 [app] [I] Completed 302 Found in 1288ms (ActiveRecord: > 16.9ms) > 2016-03-31 06:30:47 [app] [I] > > > > Started GET "/hosts/wellminiondev.niwa.local" for 192.168.81.51 at > 2016-03-31 06:30:47 +1300 > 2016-03-31 06:30:47 [app] [I] Processing by HostsController#show as HTML > 2016-03-31 06:30:47 [app] [I] Parameters: > {"id"=>"wellminiondev.niwa.local"} > 2016-03-31 06:30:47 [app] [D] Setting current user thread-local variable to > Dylan Baars > 2016-03-31 06:30:47 [app] [D] Setting current organization thread-local > variable to NIWA > 2016-03-31 06:30:47 [app] [D] Setting current location thread-local > variable to none > 2016-03-31 06:30:47 [app] [D] Deface: 1 overrides found for 'hosts/show' > 2016-03-31 06:30:47 [app] [D] Deface: 'add_system_link_to_host' matched 1 > times with 'td:first' > 2016-03-31 06:30:47 [app] [I] Deface: [WARNING] No :original defined for > 'add_system_link_to_host', you should change its definition to include: > > :original => '68201d5314be8a5aeb05b063bc5cd0afaf58a6c5' > 2016-03-31 06:30:48 [app] [I] Rendered hosts/_metrics.html.erb (1.2ms) > 2016-03-31 06:30:48 [app] [I] Rendered hosts/show.html.erb within > layouts/application (948.3ms) > 2016-03-31 06:30:48 [app] [I] Rendered home/_user_dropdown.html.erb > (239.2ms) > 2016-03-31 06:30:48 [app] [I] Read fragment views/tabs_and_title_records-4 > (0.3ms) > 2016-03-31 06:30:48 [app] [I] Rendered home/_topbar.html.erb (242.4ms) > 2016-03-31 06:30:48 [app] [I] Rendered layouts/base.html.erb (246.2ms) > 2016-03-31 06:30:48 [app] [I] Completed 200 OK in 1557ms (Views: 1416.4ms | > ActiveRecord: 27.6ms) > 2016-03-31 06:30:49 [app] [I] > > > > Started GET "/hosts/wellminiondev.niwa.local/overview" for 192.168.81.51 > at 2016-03-31 06:30:49 +1300 > 2016-03-31 06:30:49 [app] [I] Processing by HostsController#overview as HTML > 2016-03-31 06:30:49 [app] [I] Parameters: > {"id"=>"wellminiondev.niwa.local"} > 2016-03-31 06:30:49 [app] [D] Setting current user thread-local variable to > Dylan Baars > 2016-03-31 06:30:49 [app] [D] Setting current organization thread-local > variable to NIWA > 2016-03-31 06:30:49 [app] [D] Setting current location thread-local > variable to none > 2016-03-31 06:30:49 [app] [I] > > > > Started GET "/hosts/wellminiondev.niwa.local/nics" for 192.168.81.51 at > 2016-03-31 06:30:49 +1300 > 2016-03-31 06:30:49 [app] [D] Deface: 1 overrides found for > 'hosts/_overview' > 2016-03-31 06:30:49 [app] [D] Deface: 'add_system_status_to_host' matched 1 > times with 'tr:first-child' > 2016-03-31 06:30:49 [app] [I] Deface: [WARNING] No :original defined for > 'add_system_status_to_host', you should change its definition to include: > > :original => '68e6b32c550fbc7beca04e60b2851003b1f3afed' > 2016-03-31 06:30:49 [app] [I] Processing by HostsController#nics as HTML > 2016-03-31 06:30:49 [app] [I] Parameters: > {"id"=>"wellminiondev.niwa.local"} > 2016-03-31 06:30:49 [app] [I] > > > > Started GET "/hosts/wellminiondev.niwa.local/resources?range=7" for > 192.168.81.51 at 2016-03-31 06:30:49 +1300 > 2016-03-31 06:30:49 [app] [D] Setting current user thread-local variable to > Dylan Baars > 2016-03-31 06:30:49 [app] [I] > > > > Started GET "/hosts/wellminiondev.niwa.local/runtime?range=7" for > 192.168.81.51 at 2016-03-31 06:30:49 +1300 > 2016-03-31 06:30:49 [app] [D] Setting current organization thread-local > variable to NIWA > 2016-03-31 06:30:49 [app] [D] Setting current location thread-local > variable to none > 2016-03-31 06:30:49 [app] [I] Processing by HostsController#runtime as HTML > 2016-03-31 06:30:49 [app] [I] Parameters: {"range"=>"7", > "id"=>"wellminiondev.niwa.local"} > 2016-03-31 06:30:49 [app] [I] Processing by HostsController#resources as > HTML > 2016-03-31 06:30:49 [app] [I] Parameters: {"range"=>"7", > "id"=>"wellminiondev.niwa.local"} > 2016-03-31 06:30:49 [app] [D] Setting current user thread-local variable to > Dylan Baars > 2016-03-31 06:30:49 [app] [D] Setting current user thread-local variable to > Dylan Baars > 2016-03-31 06:30:49 [app] [D] Setting current organization thread-local > variable to NIWA > 2016-03-31 06:30:49 [app] [D] Setting current location thread-local > variable to none > 2016-03-31 06:30:49 [app] [I] Rendered hosts/_nics.html.erb (20.0ms) > 2016-03-31 06:30:49 [app] [I] Completed 200 OK in 69ms (Views: 11.3ms | > ActiveRecord: 36.6ms) > 2016-03-31 06:30:49 [app] [D] Setting current organization thread-local > variable to NIWA > 2016-03-31 06:30:49 [app] [D] Setting current location thread-local > variable to none > 2016-03-31 06:30:49 [app] [I] > > > > Started GET "/hosts/wellminiondev.niwa.local/templates" for > 192.168.81.51 at 2016-03-31 06:30:49 +1300 > 2016-03-31 06:30:50 [app] [I] Rendered hosts/_resources.html.erb (320.1ms) > 2016-03-31 06:30:50 [app] [I] Completed 200 OK in 755ms (Views: 714.7ms | > ActiveRecord: 19.3ms) > 2016-03-31 06:30:50 [app] [I] Rendered hosts/_overview.html.erb (931.7ms) > 2016-03-31 06:30:50 [app] [I] Completed 200 OK in 974ms (Views: 744.6ms | > ActiveRecord: 204.4ms) > 2016-03-31 06:30:50 [app] [I] Rendered hosts/_runtime.html.erb (1339.7ms) > 2016-03-31 06:30:50 [app] [I] Completed 200 OK in 1415ms (Views: 874.3ms | > ActiveRecord: 511.4ms) > 2016-03-31 06:30:51 [app] [I] Processing by HostsController#templates as > HTML > 2016-03-31 06:30:51 [app] [I] Parameters: > {"id"=>"wellminiondev.niwa.local"} > 2016-03-31 06:30:51 [app] [D] Setting current user thread-local variable to > Dylan Baars > 2016-03-31 06:30:51 [app] [D] Setting current organization thread-local > variable to NIWA > 2016-03-31 06:30:51 [app] [D] Setting current location thread-local > variable to none > 2016-03-31 06:30:52 [app] [I] Rendered text template (0.0ms) > 2016-03-31 06:30:52 [app] [I] Completed 200 OK in 1767ms (Views: 257.3ms | > ActiveRecord: 21.3ms) > 2016-03-31 06:30:53 [foreman-tasks/dynflow] [I] start terminating > throttle_limiter... > 2016-03-31 06:30:53 [foreman-tasks/dynflow] [I] start terminating client > dispatcher... > 2016-03-31 06:30:53 [foreman-tasks/dynflow] [I] stop listening for new > events... > 2016-03-31 06:30:53 [foreman-tasks/dynflow] [I] start terminating clock... > 2016-03-31 06:30:54 [foreman-tasks/dynflow] [I] start terminating > throttle_limiter... > 2016-03-31 06:30:54 [foreman-tasks/dynflow] [I] start terminating client > dispatcher... > 2016-03-31 06:30:54 [foreman-tasks/dynflow] [I] stop listening for new > events... > 2016-03-31 06:30:54 [foreman-tasks/dynflow] [I] start terminating clock... > 2016-03-31 06:32:10 [app] [I] > > > > Started POST "/salt/api/v2/jobs/upload" for 192.168.14.100 at 2016-03-31 > 06:32:10 +1300 > 2016-03-31 06:32:10 [app] [I] Processing by > ForemanSalt::Api::V2::JobsController#upload as JSON > 2016-03-31 06:32:10 [app] [I] Parameters: > {"job"=>{"function"=>"state.highstate", > "result"=>{"wellminiondev.niwa.local"=>{"pkg_|-httpd_|-httpd_|-installed"=>{"comment"=>"Package > httpd is already installed", "name"=>"httpd", > "start_time"=>"06:31:42.106300", "result"=>true, "duration"=>2.279, > "__run_num__"=>1, "changes"=>{}}, > "pkg_|-nano_|-nano_|-installed"=>{"comment"=>"Package nano is already > installed", "name"=>"nano", "start_time"=>"06:31:41.098023", > "result"=>true, "duration"=>1007.931, "__run_num__"=>0, "changes"=>{}}}}, > "job_id"=>"20160331063047033123"}, "apiv"=>"v2"} > 2016-03-31 06:32:10 [app] [D] Verifying request from > ["wellkatellodev.niwa.local"] against ["wellkatellodev.niwa.local"] > 2016-03-31 06:32:10 [app] [D] Setting current user thread-local variable to > API Admin > 2016-03-31 06:32:10 [app] [I] Processing job 20160331063047033123 from Salt. > 2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] ExecutionPlan > 41e4ddb7-8ea1-496a-a91c-8ac41af03ba6 pending >> planning > 2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] Step > 41e4ddb7-8ea1-496a-a91c-8ac41af03ba6: 1 pending >> running in phase > Plan Actions::ForemanSalt::ReportImport > 2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] Step > 41e4ddb7-8ea1-496a-a91c-8ac41af03ba6: 1 running >> success in phase > Plan Actions::ForemanSalt::ReportImport > 2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] ExecutionPlan > 41e4ddb7-8ea1-496a-a91c-8ac41af03ba6 planning >> planned > 2016-03-31 06:32:11 [app] [D] Body: > {"task_id":"45e6aae0-a06b-4199-b27b-901e864ea244"} > 2016-03-31 06:32:11 [app] [I] Completed 200 OK in 910ms (Views: 0.4ms | > ActiveRecord: 282.6ms) > 2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] ExecutionPlan > 41e4ddb7-8ea1-496a-a91c-8ac41af03ba6 planned >> running > 2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] Step > 41e4ddb7-8ea1-496a-a91c-8ac41af03ba6: 2 pending >> running in phase > Run Actions::ForemanSalt::ReportImport > 2016-03-31 06:32:11 [app] [D] Setting current user thread-local variable to > Anonymous Admin > 2016-03-31 06:32:12 [app] [I] processing report for wellminiondev.niwa.local > 2016-03-31 06:32:12 [app] [D] Report: > {"pkg_|-httpd_|-httpd_|-installed"=>{"comment"=>"Package httpd is already > installed", "name"=>"httpd", "start_time"=>"06:31:42.106300", > "result"=>true, "duration"=>2.279, "__run_num__"=>1, "changes"=>{}}, > "pkg_|-nano_|-nano_|-installed"=>{"comment"=>"Package nano is already > installed", "name"=>"nano", "start_time"=>"06:31:41.098023", > "result"=>true, "duration"=>1007.931, "__run_num__"=>0, "changes"=>{}}} > 2016-03-31 06:32:13 [app] [I] Imported report for wellminiondev.niwa.local > in 0.77 seconds > 2016-03-31 06:32:13 [foreman-tasks/dynflow] [D] Step > 41e4ddb7-8ea1-496a-a91c-8ac41af03ba6: 2 running >> success in phase > Run Actions::ForemanSalt::ReportImport > 2016-03-31 06:32:13 [foreman-tasks/dynflow] [D] ExecutionPlan > 41e4ddb7-8ea1-496a-a91c-8ac41af03ba6 running >> stopped > > > and here's the /var/log/salt/master output for the same command > > 2016-03-31 06:30:47,174 [salt.loaded.int.module.cmdmod][INFO ][3294] > Executing command '/usr/bin/foreman-node wellminiondev.niwa.local' in > directory '/root' > 2016-03-31 06:31:13,591 [salt.loaded.int.module.cmdmod][ERROR ][3294] > Command '/usr/bin/foreman-node wellminiondev.niwa.local' failed with return > code: 1 > 2016-03-31 06:31:13,594 [salt.loaded.int.module.cmdmod][ERROR ][3294] > output: Couldn't retrieve ENC data: execution expired > 2016-03-31 06:31:13,596 [salt.loaded.int.pillar.puppet][CRITICAL][3294] > YAML data from /usr/bin/foreman-node failed to parse > 2016-03-31 06:31:13,660 [salt.utils.lazy ][DEBUG ][3292] LazyLoaded > roots.envs > 2016-03-31 06:31:40,102 [salt.loaded.int.top.ext_nodes][INFO ][3295] > master_tops ext_nodes call did not have a dictionary with a "classes" key. > 2016-03-31 06:31:41,689 [salt.config ][DEBUG ][3288] Reading > configuration from /etc/salt/master > 2016-03-31 06:31:41,847 [salt.config ][DEBUG ][3288] Including > configuration from '/etc/salt/minion.d/_schedule.conf' > 2016-03-31 06:31:41,847 [salt.config ][DEBUG ][3288] Reading > configuration from /etc/salt/minion.d/_schedule.conf > 2016-03-31 06:31:41,851 [salt.config ][DEBUG ][3288] Using cached > minion ID from /etc/salt/minion_id: wellkatellodev.niwa.local > 2016-03-31 06:31:41,853 [salt.config ][DEBUG ][3288] Reading > configuration from /etc/salt/master > 2016-03-31 06:31:42,215 [salt.utils.job ][INFO ][3291] Got return from > wellminiondev.niwa.local for job 20160331063047033123 > 2016-03-31 06:31:42,215 [salt.utils.event ][DEBUG ][3291] Sending event - > data = {'fun_args': [], 'jid': '20160331063047033123', 'return': > {'pkg_|-httpd_|-httpd_|-installed': {'comment': 'Package httpd is already > installed', 'name': 'httpd', 'start_time': '06:31:42.106300', 'result': > True, 'duration': 2.279, '__run_num__': 1, 'changes': {}}, > 'pkg_|-nano_|-nano_|-installed': {'comment': 'Package nano is already > installed', 'name': 'nano', 'start_time': '06:31:41.098023', 'result': > True, 'duration': 1007.931, '__run_num__': 0, 'changes': {}}}, 'retcode': > 0, 'success': True, 'cmd': '_return', '_stamp': > '2016-03-30T17:31:42.215041', 'fun': 'state.highstate', 'id': > 'wellminiondev.niwa.local', 'out': 'highstate'} > 2016-03-31 06:32:07,306 [salt.utils.lazy ][DEBUG ][3288] LazyLoaded > local_cache.clean_old_jobs > 2016-03-31 06:32:07,319 [salt.utils.lazy ][DEBUG ][3288] Could not > LazyLoad config.merge > 2016-03-31 06:32:07,320 [salt.fileserver ][DEBUG ][3288] Updating roots > fileserver cache > 2016-03-31 06:32:07,321 [salt.utils.verify][DEBUG ][3288] This > salt-master instance has accepted 2 minion keys. > 2016-03-31 06:33:07,371 [salt.config ][DEBUG ][3288] Reading > configuration from /etc/salt/master > 2016-03-31 06:33:07,468 [salt.config ][DEBUG ][3288] Including > configuration from '/etc/salt/minion.d/_schedule.conf' > 2016-03-31 06:33:07,469 [salt.config ][DEBUG ][3288] Reading > configuration from /etc/salt/minion.d/_schedule.conf > 2016-03-31 06:33:07,471 [salt.config ][DEBUG ][3288] Using cached > minion ID from /etc/salt/minion_id: wellkatellodev.niwa.local > 2016-03-31 06:33:07,473 [salt.config ][DEBUG ][3288] Reading > configuration from /etc/salt/master > > Foreman-tasks service is running > > [root@wellkatellodev ~]# systemctl status foreman-tasks > ● foreman-tasks.service - Foreman jobs daemon > Loaded: loaded (/usr/lib/systemd/system/foreman-tasks.service; enabled; > vendor preset: disabled) > Active: active (running) since Thu 2016-03-31 06:27:47 NZDT; 7min ago > Docs: https://github.com/theforeman/foreman-tasks > Process: 1651 ExecStart=/usr/bin/foreman-tasks start (code=exited, > status=0/SUCCESS) > CGroup: /system.slice/foreman-tasks.service > ├─3656 dynflow_executor > └─3662 dynflow_executor_monitor > > Mar 31 06:27:16 wellkatellodev.niwa.local systemd[1]: Starting Foreman jobs > daemon... > Mar 31 06:27:46 wellkatellodev.niwa.local foreman-tasks[1651]: Dynflow > Executor: start in progress > Mar 31 06:27:47 wellkatellodev.niwa.local foreman-tasks[1651]: > dynflow_executor: process with pid 3656 started. > Mar 31 06:27:47 wellkatellodev.niwa.local systemd[1]: Started Foreman jobs > daemon. > > > > Thanks again for your help, it's much appreciated! > Dylan > > On Thursday, March 31, 2016 at 12:08:30 AM UTC+13, stephen wrote: > > > > > > > > ----- Original Message ----- > > > From: "Dylan Baars" <baa...@gmail.com > > > > To: "Foreman users" <forema...@googlegroups.com > > > > Cc: ste...@redhat.com > > > Sent: Wednesday, March 30, 2016 12:54:53 AM > > > Subject: Re: [foreman-users] Importing salt states fails ERF12-4701 > > > > > > OK, re-reading the docs says > > > > > > "Foreman provides an interface for adding Salt states to either a > > Foreman > > > host group or a host. Salt will know to apply these states through the > > > external node classification feature. This is done in addition to > > top.sls." > > > > > > I assume that's this part in /etc/salt/master > > > > > > master_tops: > > > ext_nodes: /usr/bin/foreman-node > > > > > > so seems correct? However if I run that manually (assuming "foreman-node > > > salt-minion-name" is what it is attempting to do) > > > > > > [root@wellkatellodev salt]# /usr/bin/foreman-node > > wellminiondev.niwa.local > > > Couldn't retrieve ENC data: execution expired > > > > > > Did you start the foreman-tasks service on the foreman? > > > > > > Can you provide the foreman production log? > > > > > Back to it running via the foreman GUI "Run Salt" button - I see this in > > > the /var/log/salt/master logs > > > > > > 2016-03-30 17:48:44,649 [salt.utils.event ][DEBUG ][3301] Sending > > event - > > > data = {'_stamp': '2016-03-30T04:48:44.648530', 'minions': > > > ['wellminiondev.niwa.local']}

Sorry I take that back, I see the execution expired error in the salt logs but not in the foreman.

It'd be useful if you could still run foreman-node by itself and share the production.log when you do.

Also /etc/salt/foreman.yaml, if you've made any changes since the first message.

··· ----- Original Message ----- > From: "Stephen Benjamin" > To: "Dylan Baars" > Cc: "Foreman users" > Sent: Wednesday, March 30, 2016 3:15:52 PM > Subject: Re: [foreman-users] Importing salt states fails ERF12-4701 > > I don't see any errors here, it looks like Salt ran successfully, and even > uploaded a report to Foreman. > > Can you run `foreman-node fqdn` like in your other message, and share the > production.log if you still get an error? > > > ----- Original Message ----- > > From: "Dylan Baars" > > To: "Foreman users" > > Cc: stephen@redhat.com > > Sent: Wednesday, March 30, 2016 1:40:58 PM > > Subject: Re: [foreman-users] Importing salt states fails ERF12-4701 > > > > Morning, > > > > with debug logging for foreman enabled - edited /etc/foreman/settings.yaml > > > > :logging: > > # :level: info > > :level: debug > > > > > > this is what is output when I hit "Run Salt" in the GUI > > > > > Started GET "/salt/run/wellminiondev.niwa.local" for 192.168.81.51 at > > 2016-03-31 06:30:45 +1300 > > 2016-03-31 06:30:45 [app] [I] Processing by > > ForemanSalt::MinionsController#run as HTML > > 2016-03-31 06:30:45 [app] [I] Parameters: > > {"id"=>"wellminiondev.niwa.local"} > > 2016-03-31 06:30:45 [app] [D] Setting current user thread-local variable to > > Dylan Baars > > 2016-03-31 06:30:45 [app] [D] Setting current organization thread-local > > variable to NIWA > > 2016-03-31 06:30:45 [app] [D] Setting current location thread-local > > variable to none > > 2016-03-31 06:30:47 [app] [I] Redirected to > > https://wellkatellodev.niwa.local/hosts/wellminiondev.niwa.local > > 2016-03-31 06:30:47 [app] [I] Completed 302 Found in 1288ms (ActiveRecord: > > 16.9ms) > > 2016-03-31 06:30:47 [app] [I] > > > > > > Started GET "/hosts/wellminiondev.niwa.local" for 192.168.81.51 at > > 2016-03-31 06:30:47 +1300 > > 2016-03-31 06:30:47 [app] [I] Processing by HostsController#show as HTML > > 2016-03-31 06:30:47 [app] [I] Parameters: > > {"id"=>"wellminiondev.niwa.local"} > > 2016-03-31 06:30:47 [app] [D] Setting current user thread-local variable to > > Dylan Baars > > 2016-03-31 06:30:47 [app] [D] Setting current organization thread-local > > variable to NIWA > > 2016-03-31 06:30:47 [app] [D] Setting current location thread-local > > variable to none > > 2016-03-31 06:30:47 [app] [D] Deface: 1 overrides found for 'hosts/show' > > 2016-03-31 06:30:47 [app] [D] Deface: 'add_system_link_to_host' matched 1 > > times with 'td:first' > > 2016-03-31 06:30:47 [app] [I] Deface: [WARNING] No :original defined for > > 'add_system_link_to_host', you should change its definition to include: > > > :original => '68201d5314be8a5aeb05b063bc5cd0afaf58a6c5' > > 2016-03-31 06:30:48 [app] [I] Rendered hosts/_metrics.html.erb (1.2ms) > > 2016-03-31 06:30:48 [app] [I] Rendered hosts/show.html.erb within > > layouts/application (948.3ms) > > 2016-03-31 06:30:48 [app] [I] Rendered home/_user_dropdown.html.erb > > (239.2ms) > > 2016-03-31 06:30:48 [app] [I] Read fragment views/tabs_and_title_records-4 > > (0.3ms) > > 2016-03-31 06:30:48 [app] [I] Rendered home/_topbar.html.erb (242.4ms) > > 2016-03-31 06:30:48 [app] [I] Rendered layouts/base.html.erb (246.2ms) > > 2016-03-31 06:30:48 [app] [I] Completed 200 OK in 1557ms (Views: 1416.4ms | > > ActiveRecord: 27.6ms) > > 2016-03-31 06:30:49 [app] [I] > > > > > > Started GET "/hosts/wellminiondev.niwa.local/overview" for 192.168.81.51 > > at 2016-03-31 06:30:49 +1300 > > 2016-03-31 06:30:49 [app] [I] Processing by HostsController#overview as > > HTML > > 2016-03-31 06:30:49 [app] [I] Parameters: > > {"id"=>"wellminiondev.niwa.local"} > > 2016-03-31 06:30:49 [app] [D] Setting current user thread-local variable to > > Dylan Baars > > 2016-03-31 06:30:49 [app] [D] Setting current organization thread-local > > variable to NIWA > > 2016-03-31 06:30:49 [app] [D] Setting current location thread-local > > variable to none > > 2016-03-31 06:30:49 [app] [I] > > > > > > Started GET "/hosts/wellminiondev.niwa.local/nics" for 192.168.81.51 at > > 2016-03-31 06:30:49 +1300 > > 2016-03-31 06:30:49 [app] [D] Deface: 1 overrides found for > > 'hosts/_overview' > > 2016-03-31 06:30:49 [app] [D] Deface: 'add_system_status_to_host' matched 1 > > times with 'tr:first-child' > > 2016-03-31 06:30:49 [app] [I] Deface: [WARNING] No :original defined for > > 'add_system_status_to_host', you should change its definition to include: > > > :original => '68e6b32c550fbc7beca04e60b2851003b1f3afed' > > 2016-03-31 06:30:49 [app] [I] Processing by HostsController#nics as HTML > > 2016-03-31 06:30:49 [app] [I] Parameters: > > {"id"=>"wellminiondev.niwa.local"} > > 2016-03-31 06:30:49 [app] [I] > > > > > > Started GET "/hosts/wellminiondev.niwa.local/resources?range=7" for > > 192.168.81.51 at 2016-03-31 06:30:49 +1300 > > 2016-03-31 06:30:49 [app] [D] Setting current user thread-local variable to > > Dylan Baars > > 2016-03-31 06:30:49 [app] [I] > > > > > > Started GET "/hosts/wellminiondev.niwa.local/runtime?range=7" for > > 192.168.81.51 at 2016-03-31 06:30:49 +1300 > > 2016-03-31 06:30:49 [app] [D] Setting current organization thread-local > > variable to NIWA > > 2016-03-31 06:30:49 [app] [D] Setting current location thread-local > > variable to none > > 2016-03-31 06:30:49 [app] [I] Processing by HostsController#runtime as HTML > > 2016-03-31 06:30:49 [app] [I] Parameters: {"range"=>"7", > > "id"=>"wellminiondev.niwa.local"} > > 2016-03-31 06:30:49 [app] [I] Processing by HostsController#resources as > > HTML > > 2016-03-31 06:30:49 [app] [I] Parameters: {"range"=>"7", > > "id"=>"wellminiondev.niwa.local"} > > 2016-03-31 06:30:49 [app] [D] Setting current user thread-local variable to > > Dylan Baars > > 2016-03-31 06:30:49 [app] [D] Setting current user thread-local variable to > > Dylan Baars > > 2016-03-31 06:30:49 [app] [D] Setting current organization thread-local > > variable to NIWA > > 2016-03-31 06:30:49 [app] [D] Setting current location thread-local > > variable to none > > 2016-03-31 06:30:49 [app] [I] Rendered hosts/_nics.html.erb (20.0ms) > > 2016-03-31 06:30:49 [app] [I] Completed 200 OK in 69ms (Views: 11.3ms | > > ActiveRecord: 36.6ms) > > 2016-03-31 06:30:49 [app] [D] Setting current organization thread-local > > variable to NIWA > > 2016-03-31 06:30:49 [app] [D] Setting current location thread-local > > variable to none > > 2016-03-31 06:30:49 [app] [I] > > > > > > Started GET "/hosts/wellminiondev.niwa.local/templates" for > > 192.168.81.51 at 2016-03-31 06:30:49 +1300 > > 2016-03-31 06:30:50 [app] [I] Rendered hosts/_resources.html.erb > > (320.1ms) > > 2016-03-31 06:30:50 [app] [I] Completed 200 OK in 755ms (Views: 714.7ms | > > ActiveRecord: 19.3ms) > > 2016-03-31 06:30:50 [app] [I] Rendered hosts/_overview.html.erb (931.7ms) > > 2016-03-31 06:30:50 [app] [I] Completed 200 OK in 974ms (Views: 744.6ms | > > ActiveRecord: 204.4ms) > > 2016-03-31 06:30:50 [app] [I] Rendered hosts/_runtime.html.erb (1339.7ms) > > 2016-03-31 06:30:50 [app] [I] Completed 200 OK in 1415ms (Views: 874.3ms | > > ActiveRecord: 511.4ms) > > 2016-03-31 06:30:51 [app] [I] Processing by HostsController#templates as > > HTML > > 2016-03-31 06:30:51 [app] [I] Parameters: > > {"id"=>"wellminiondev.niwa.local"} > > 2016-03-31 06:30:51 [app] [D] Setting current user thread-local variable to > > Dylan Baars > > 2016-03-31 06:30:51 [app] [D] Setting current organization thread-local > > variable to NIWA > > 2016-03-31 06:30:51 [app] [D] Setting current location thread-local > > variable to none > > 2016-03-31 06:30:52 [app] [I] Rendered text template (0.0ms) > > 2016-03-31 06:30:52 [app] [I] Completed 200 OK in 1767ms (Views: 257.3ms | > > ActiveRecord: 21.3ms) > > 2016-03-31 06:30:53 [foreman-tasks/dynflow] [I] start terminating > > throttle_limiter... > > 2016-03-31 06:30:53 [foreman-tasks/dynflow] [I] start terminating client > > dispatcher... > > 2016-03-31 06:30:53 [foreman-tasks/dynflow] [I] stop listening for new > > events... > > 2016-03-31 06:30:53 [foreman-tasks/dynflow] [I] start terminating clock... > > 2016-03-31 06:30:54 [foreman-tasks/dynflow] [I] start terminating > > throttle_limiter... > > 2016-03-31 06:30:54 [foreman-tasks/dynflow] [I] start terminating client > > dispatcher... > > 2016-03-31 06:30:54 [foreman-tasks/dynflow] [I] stop listening for new > > events... > > 2016-03-31 06:30:54 [foreman-tasks/dynflow] [I] start terminating clock... > > 2016-03-31 06:32:10 [app] [I] > > > > > > Started POST "/salt/api/v2/jobs/upload" for 192.168.14.100 at 2016-03-31 > > 06:32:10 +1300 > > 2016-03-31 06:32:10 [app] [I] Processing by > > ForemanSalt::Api::V2::JobsController#upload as JSON > > 2016-03-31 06:32:10 [app] [I] Parameters: > > {"job"=>{"function"=>"state.highstate", > > "result"=>{"wellminiondev.niwa.local"=>{"pkg_|-httpd_|-httpd_|-installed"=>{"comment"=>"Package > > httpd is already installed", "name"=>"httpd", > > "start_time"=>"06:31:42.106300", "result"=>true, "duration"=>2.279, > > "__run_num__"=>1, "changes"=>{}}, > > "pkg_|-nano_|-nano_|-installed"=>{"comment"=>"Package nano is already > > installed", "name"=>"nano", "start_time"=>"06:31:41.098023", > > "result"=>true, "duration"=>1007.931, "__run_num__"=>0, "changes"=>{}}}}, > > "job_id"=>"20160331063047033123"}, "apiv"=>"v2"} > > 2016-03-31 06:32:10 [app] [D] Verifying request from > > ["wellkatellodev.niwa.local"] against ["wellkatellodev.niwa.local"] > > 2016-03-31 06:32:10 [app] [D] Setting current user thread-local variable to > > API Admin > > 2016-03-31 06:32:10 [app] [I] Processing job 20160331063047033123 from > > Salt. > > 2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] ExecutionPlan > > 41e4ddb7-8ea1-496a-a91c-8ac41af03ba6 pending >> planning > > 2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] Step > > 41e4ddb7-8ea1-496a-a91c-8ac41af03ba6: 1 pending >> running in phase > > Plan Actions::ForemanSalt::ReportImport > > 2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] Step > > 41e4ddb7-8ea1-496a-a91c-8ac41af03ba6: 1 running >> success in phase > > Plan Actions::ForemanSalt::ReportImport > > 2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] ExecutionPlan > > 41e4ddb7-8ea1-496a-a91c-8ac41af03ba6 planning >> planned > > 2016-03-31 06:32:11 [app] [D] Body: > > {"task_id":"45e6aae0-a06b-4199-b27b-901e864ea244"} > > 2016-03-31 06:32:11 [app] [I] Completed 200 OK in 910ms (Views: 0.4ms | > > ActiveRecord: 282.6ms) > > 2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] ExecutionPlan > > 41e4ddb7-8ea1-496a-a91c-8ac41af03ba6 planned >> running > > 2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] Step > > 41e4ddb7-8ea1-496a-a91c-8ac41af03ba6: 2 pending >> running in phase > > Run Actions::ForemanSalt::ReportImport > > 2016-03-31 06:32:11 [app] [D] Setting current user thread-local variable to > > Anonymous Admin > > 2016-03-31 06:32:12 [app] [I] processing report for > > wellminiondev.niwa.local > > 2016-03-31 06:32:12 [app] [D] Report: > > {"pkg_|-httpd_|-httpd_|-installed"=>{"comment"=>"Package httpd is already > > installed", "name"=>"httpd", "start_time"=>"06:31:42.106300", > > "result"=>true, "duration"=>2.279, "__run_num__"=>1, "changes"=>{}}, > > "pkg_|-nano_|-nano_|-installed"=>{"comment"=>"Package nano is already > > installed", "name"=>"nano", "start_time"=>"06:31:41.098023", > > "result"=>true, "duration"=>1007.931, "__run_num__"=>0, "changes"=>{}}} > > 2016-03-31 06:32:13 [app] [I] Imported report for wellminiondev.niwa.local > > in 0.77 seconds > > 2016-03-31 06:32:13 [foreman-tasks/dynflow] [D] Step > > 41e4ddb7-8ea1-496a-a91c-8ac41af03ba6: 2 running >> success in phase > > Run Actions::ForemanSalt::ReportImport > > 2016-03-31 06:32:13 [foreman-tasks/dynflow] [D] ExecutionPlan > > 41e4ddb7-8ea1-496a-a91c-8ac41af03ba6 running >> stopped > > > > > > and here's the /var/log/salt/master output for the same command > > > > 2016-03-31 06:30:47,174 [salt.loaded.int.module.cmdmod][INFO ][3294] > > Executing command '/usr/bin/foreman-node wellminiondev.niwa.local' in > > directory '/root' > > 2016-03-31 06:31:13,591 [salt.loaded.int.module.cmdmod][ERROR ][3294] > > Command '/usr/bin/foreman-node wellminiondev.niwa.local' failed with return > > code: 1 > > 2016-03-31 06:31:13,594 [salt.loaded.int.module.cmdmod][ERROR ][3294] > > output: Couldn't retrieve ENC data: execution expired > > 2016-03-31 06:31:13,596 [salt.loaded.int.pillar.puppet][CRITICAL][3294] > > YAML data from /usr/bin/foreman-node failed to parse > > 2016-03-31 06:31:13,660 [salt.utils.lazy ][DEBUG ][3292] LazyLoaded > > roots.envs > > 2016-03-31 06:31:40,102 [salt.loaded.int.top.ext_nodes][INFO ][3295] > > master_tops ext_nodes call did not have a dictionary with a "classes" key. > > 2016-03-31 06:31:41,689 [salt.config ][DEBUG ][3288] Reading > > configuration from /etc/salt/master > > 2016-03-31 06:31:41,847 [salt.config ][DEBUG ][3288] Including > > configuration from '/etc/salt/minion.d/_schedule.conf' > > 2016-03-31 06:31:41,847 [salt.config ][DEBUG ][3288] Reading > > configuration from /etc/salt/minion.d/_schedule.conf > > 2016-03-31 06:31:41,851 [salt.config ][DEBUG ][3288] Using cached > > minion ID from /etc/salt/minion_id: wellkatellodev.niwa.local > > 2016-03-31 06:31:41,853 [salt.config ][DEBUG ][3288] Reading > > configuration from /etc/salt/master > > 2016-03-31 06:31:42,215 [salt.utils.job ][INFO ][3291] Got return from > > wellminiondev.niwa.local for job 20160331063047033123 > > 2016-03-31 06:31:42,215 [salt.utils.event ][DEBUG ][3291] Sending event - > > data = {'fun_args': [], 'jid': '20160331063047033123', 'return': > > {'pkg_|-httpd_|-httpd_|-installed': {'comment': 'Package httpd is already > > installed', 'name': 'httpd', 'start_time': '06:31:42.106300', 'result': > > True, 'duration': 2.279, '__run_num__': 1, 'changes': {}}, > > 'pkg_|-nano_|-nano_|-installed': {'comment': 'Package nano is already > > installed', 'name': 'nano', 'start_time': '06:31:41.098023', 'result': > > True, 'duration': 1007.931, '__run_num__': 0, 'changes': {}}}, 'retcode': > > 0, 'success': True, 'cmd': '_return', '_stamp': > > '2016-03-30T17:31:42.215041', 'fun': 'state.highstate', 'id': > > 'wellminiondev.niwa.local', 'out': 'highstate'} > > 2016-03-31 06:32:07,306 [salt.utils.lazy ][DEBUG ][3288] LazyLoaded > > local_cache.clean_old_jobs > > 2016-03-31 06:32:07,319 [salt.utils.lazy ][DEBUG ][3288] Could not > > LazyLoad config.merge > > 2016-03-31 06:32:07,320 [salt.fileserver ][DEBUG ][3288] Updating roots > > fileserver cache > > 2016-03-31 06:32:07,321 [salt.utils.verify][DEBUG ][3288] This > > salt-master instance has accepted 2 minion keys. > > 2016-03-31 06:33:07,371 [salt.config ][DEBUG ][3288] Reading > > configuration from /etc/salt/master > > 2016-03-31 06:33:07,468 [salt.config ][DEBUG ][3288] Including > > configuration from '/etc/salt/minion.d/_schedule.conf' > > 2016-03-31 06:33:07,469 [salt.config ][DEBUG ][3288] Reading > > configuration from /etc/salt/minion.d/_schedule.conf > > 2016-03-31 06:33:07,471 [salt.config ][DEBUG ][3288] Using cached > > minion ID from /etc/salt/minion_id: wellkatellodev.niwa.local > > 2016-03-31 06:33:07,473 [salt.config ][DEBUG ][3288] Reading > > configuration from /etc/salt/master > > > > Foreman-tasks service is running > > > > [root@wellkatellodev ~]# systemctl status foreman-tasks > > ● foreman-tasks.service - Foreman jobs daemon > > Loaded: loaded (/usr/lib/systemd/system/foreman-tasks.service; enabled; > > vendor preset: disabled) > > Active: active (running) since Thu 2016-03-31 06:27:47 NZDT; 7min ago > > Docs: https://github.com/theforeman/foreman-tasks > > Process: 1651 ExecStart=/usr/bin/foreman-tasks start (code=exited, > > status=0/SUCCESS) > > CGroup: /system.slice/foreman-tasks.service > > ├─3656 dynflow_executor > > └─3662 dynflow_executor_monitor > > > > Mar 31 06:27:16 wellkatellodev.niwa.local systemd[1]: Starting Foreman jobs > > daemon... > > Mar 31 06:27:46 wellkatellodev.niwa.local foreman-tasks[1651]: Dynflow > > Executor: start in progress > > Mar 31 06:27:47 wellkatellodev.niwa.local foreman-tasks[1651]: > > dynflow_executor: process with pid 3656 started. > > Mar 31 06:27:47 wellkatellodev.niwa.local systemd[1]: Started Foreman jobs > > daemon. > > > > > > > > Thanks again for your help, it's much appreciated! > > Dylan > > > > On Thursday, March 31, 2016 at 12:08:30 AM UTC+13, stephen wrote: > > > > > > > > > > > > ----- Original Message ----- > > > > From: "Dylan Baars" <baa...@gmail.com > > > > > To: "Foreman users" <forema...@googlegroups.com > > > > > Cc: ste...@redhat.com

For completeness - here's /etc/salt/foreman.yaml

··· --- :proto: https :host: wellkatellodev.niwa.local :port: 443 :timeout: 10 :salt: /usr/bin/salt :upload_grains: true :ssl_ca: "/etc/puppet/ssl_ca.pem" :ssl_cert: "/etc/puppet/client_cert.pem" :ssl_key: "/etc/puppet/client_key.pem"

and running foreman-node

[root@wellkatellodev ~]# /usr/bin/foreman-node wellminiondev.niwa.local
Couldn’t retrieve ENC data: execution expired
[root@wellkatellodev ~]#

nothing appeared in production.log at all. Just to prove I’m getting the
fqdn right -

[root@wellkatellodev ~]# hammer host list
—|---------------------------|------------------|------------|----------------|------------------
ID | NAME | OPERATING SYSTEM | HOST GROUP | IP
> MAC
—|---------------------------|------------------|------------|----------------|------------------
1 | wellkatellodev.niwa.local | CentOS 7.2 | |
192.168.14.100 | 00:50:56:85:50:23
2 | wellminiondev.niwa.local | CentOS 7.2 | |
192.168.14.102 | 00:50:56:85:14:ea
3 | wellsaltdev.niwa.local | CentOS 7.2 | |
192.168.14.101 | 00:50:56:85:76:19
—|---------------------------|------------------|------------|----------------|------------------
[root@wellkatellodev ~]#

On Thursday, March 31, 2016 at 8:18:22 AM UTC+13, stephen wrote:

Sorry I take that back, I see the execution expired error in the salt logs
but not in the foreman.

It’d be useful if you could still run foreman-node by itself and share the
production.log when you do.

Also /etc/salt/foreman.yaml, if you’ve made any changes since the first
message.

----- Original Message -----

From: “Stephen Benjamin” <ste...@redhat.com <javascript:>>
To: “Dylan Baars” <baa...@gmail.com <javascript:>>
Cc: “Foreman users” <forema...@googlegroups.com <javascript:>>
Sent: Wednesday, March 30, 2016 3:15:52 PM
Subject: Re: [foreman-users] Importing salt states fails ERF12-4701

I don’t see any errors here, it looks like Salt ran successfully, and
even
uploaded a report to Foreman.

Can you run foreman-node fqdn like in your other message, and share
the
production.log if you still get an error?

----- Original Message -----

From: “Dylan Baars” <baa...@gmail.com <javascript:>>
To: “Foreman users” <forema...@googlegroups.com <javascript:>>
Cc: ste...@redhat.com <javascript:>
Sent: Wednesday, March 30, 2016 1:40:58 PM
Subject: Re: [foreman-users] Importing salt states fails ERF12-4701

Morning,

with debug logging for foreman enabled - edited
/etc/foreman/settings.yaml

:logging:

:level: info

:level: debug

this is what is output when I hit “Run Salt” in the GUI

Started GET “/salt/run/wellminiondev.niwa.local” for 192.168.81.51
at
2016-03-31 06:30:45 +1300
2016-03-31 06:30:45 [app] [I] Processing by
ForemanSalt::MinionsController#run as HTML
2016-03-31 06:30:45 [app] [I] Parameters:
{“id”=>“wellminiondev.niwa.local”}
2016-03-31 06:30:45 [app] [D] Setting current user thread-local
variable to
Dylan Baars
2016-03-31 06:30:45 [app] [D] Setting current organization
thread-local
variable to NIWA
2016-03-31 06:30:45 [app] [D] Setting current location thread-local
variable to none
2016-03-31 06:30:47 [app] [I] Redirected to
https://wellkatellodev.niwa.local/hosts/wellminiondev.niwa.local
2016-03-31 06:30:47 [app] [I] Completed 302 Found in 1288ms
(ActiveRecord:
16.9ms)
2016-03-31 06:30:47 [app] [I]

Started GET “/hosts/wellminiondev.niwa.local” for 192.168.81.51 at
2016-03-31 06:30:47 +1300
2016-03-31 06:30:47 [app] [I] Processing by HostsController#show as
HTML
2016-03-31 06:30:47 [app] [I] Parameters:
{“id”=>“wellminiondev.niwa.local”}
2016-03-31 06:30:47 [app] [D] Setting current user thread-local
variable to
Dylan Baars
2016-03-31 06:30:47 [app] [D] Setting current organization
thread-local
variable to NIWA
2016-03-31 06:30:47 [app] [D] Setting current location thread-local
variable to none
2016-03-31 06:30:47 [app] [D] Deface: 1 overrides found for
‘hosts/show’
2016-03-31 06:30:47 [app] [D] Deface: ‘add_system_link_to_host’
matched 1
times with ‘td:first’
2016-03-31 06:30:47 [app] [I] Deface: [WARNING] No :original defined
for
‘add_system_link_to_host’, you should change its definition to
include:
:original => ‘68201d5314be8a5aeb05b063bc5cd0afaf58a6c5’
2016-03-31 06:30:48 [app] [I] Rendered hosts/_metrics.html.erb
(1.2ms)
2016-03-31 06:30:48 [app] [I] Rendered hosts/show.html.erb within
layouts/application (948.3ms)
2016-03-31 06:30:48 [app] [I] Rendered home/_user_dropdown.html.erb
(239.2ms)
2016-03-31 06:30:48 [app] [I] Read fragment
views/tabs_and_title_records-4
(0.3ms)
2016-03-31 06:30:48 [app] [I] Rendered home/_topbar.html.erb
(242.4ms)
2016-03-31 06:30:48 [app] [I] Rendered layouts/base.html.erb
(246.2ms)
2016-03-31 06:30:48 [app] [I] Completed 200 OK in 1557ms (Views:
1416.4ms |
ActiveRecord: 27.6ms)
2016-03-31 06:30:49 [app] [I]

Started GET “/hosts/wellminiondev.niwa.local/overview” for
192.168.81.51
at 2016-03-31 06:30:49 +1300
2016-03-31 06:30:49 [app] [I] Processing by HostsController#overview
as
HTML
2016-03-31 06:30:49 [app] [I] Parameters:
{“id”=>“wellminiondev.niwa.local”}
2016-03-31 06:30:49 [app] [D] Setting current user thread-local
variable to
Dylan Baars
2016-03-31 06:30:49 [app] [D] Setting current organization
thread-local
variable to NIWA
2016-03-31 06:30:49 [app] [D] Setting current location thread-local
variable to none
2016-03-31 06:30:49 [app] [I]

Started GET “/hosts/wellminiondev.niwa.local/nics” for
192.168.81.51 at
2016-03-31 06:30:49 +1300
2016-03-31 06:30:49 [app] [D] Deface: 1 overrides found for
‘hosts/_overview’
2016-03-31 06:30:49 [app] [D] Deface: ‘add_system_status_to_host’
matched 1
times with ‘tr:first-child’
2016-03-31 06:30:49 [app] [I] Deface: [WARNING] No :original defined
for
‘add_system_status_to_host’, you should change its definition to
include:
:original => ‘68e6b32c550fbc7beca04e60b2851003b1f3afed’
2016-03-31 06:30:49 [app] [I] Processing by HostsController#nics as
HTML
2016-03-31 06:30:49 [app] [I] Parameters:
{“id”=>“wellminiondev.niwa.local”}
2016-03-31 06:30:49 [app] [I]

Started GET “/hosts/wellminiondev.niwa.local/resources?range=7” for
192.168.81.51 at 2016-03-31 06:30:49 +1300
2016-03-31 06:30:49 [app] [D] Setting current user thread-local
variable to
Dylan Baars
2016-03-31 06:30:49 [app] [I]

Started GET “/hosts/wellminiondev.niwa.local/runtime?range=7” for
192.168.81.51 at 2016-03-31 06:30:49 +1300
2016-03-31 06:30:49 [app] [D] Setting current organization
thread-local
variable to NIWA
2016-03-31 06:30:49 [app] [D] Setting current location thread-local
variable to none
2016-03-31 06:30:49 [app] [I] Processing by HostsController#runtime as
HTML
2016-03-31 06:30:49 [app] [I] Parameters: {“range”=>“7”,
“id”=>“wellminiondev.niwa.local”}
2016-03-31 06:30:49 [app] [I] Processing by HostsController#resources
as
HTML
2016-03-31 06:30:49 [app] [I] Parameters: {“range”=>“7”,
“id”=>“wellminiondev.niwa.local”}
2016-03-31 06:30:49 [app] [D] Setting current user thread-local
variable to
Dylan Baars
2016-03-31 06:30:49 [app] [D] Setting current user thread-local
variable to
Dylan Baars
2016-03-31 06:30:49 [app] [D] Setting current organization
thread-local
variable to NIWA
2016-03-31 06:30:49 [app] [D] Setting current location thread-local
variable to none
2016-03-31 06:30:49 [app] [I] Rendered hosts/_nics.html.erb (20.0ms)
2016-03-31 06:30:49 [app] [I] Completed 200 OK in 69ms (Views: 11.3ms

ActiveRecord: 36.6ms)
2016-03-31 06:30:49 [app] [D] Setting current organization
thread-local
variable to NIWA
2016-03-31 06:30:49 [app] [D] Setting current location thread-local
variable to none
2016-03-31 06:30:49 [app] [I]

Started GET “/hosts/wellminiondev.niwa.local/templates” for
192.168.81.51 at 2016-03-31 06:30:49 +1300
2016-03-31 06:30:50 [app] [I] Rendered hosts/_resources.html.erb
(320.1ms)
2016-03-31 06:30:50 [app] [I] Completed 200 OK in 755ms (Views:
714.7ms |
ActiveRecord: 19.3ms)
2016-03-31 06:30:50 [app] [I] Rendered hosts/_overview.html.erb
(931.7ms)
2016-03-31 06:30:50 [app] [I] Completed 200 OK in 974ms (Views:
744.6ms |
ActiveRecord: 204.4ms)
2016-03-31 06:30:50 [app] [I] Rendered hosts/_runtime.html.erb
(1339.7ms)
2016-03-31 06:30:50 [app] [I] Completed 200 OK in 1415ms (Views:
874.3ms |
ActiveRecord: 511.4ms)
2016-03-31 06:30:51 [app] [I] Processing by HostsController#templates
as
HTML
2016-03-31 06:30:51 [app] [I] Parameters:
{“id”=>“wellminiondev.niwa.local”}
2016-03-31 06:30:51 [app] [D] Setting current user thread-local
variable to
Dylan Baars
2016-03-31 06:30:51 [app] [D] Setting current organization
thread-local
variable to NIWA
2016-03-31 06:30:51 [app] [D] Setting current location thread-local
variable to none
2016-03-31 06:30:52 [app] [I] Rendered text template (0.0ms)
2016-03-31 06:30:52 [app] [I] Completed 200 OK in 1767ms (Views:
257.3ms |
ActiveRecord: 21.3ms)
2016-03-31 06:30:53 [foreman-tasks/dynflow] [I] start terminating
throttle_limiter…
2016-03-31 06:30:53 [foreman-tasks/dynflow] [I] start terminating
client
dispatcher…
2016-03-31 06:30:53 [foreman-tasks/dynflow] [I] stop listening for new
events…
2016-03-31 06:30:53 [foreman-tasks/dynflow] [I] start terminating
clock…
2016-03-31 06:30:54 [foreman-tasks/dynflow] [I] start terminating
throttle_limiter…
2016-03-31 06:30:54 [foreman-tasks/dynflow] [I] start terminating
client
dispatcher…
2016-03-31 06:30:54 [foreman-tasks/dynflow] [I] stop listening for new
events…
2016-03-31 06:30:54 [foreman-tasks/dynflow] [I] start terminating
clock…
2016-03-31 06:32:10 [app] [I]

Started POST “/salt/api/v2/jobs/upload” for 192.168.14.100 at
2016-03-31
06:32:10 +1300
2016-03-31 06:32:10 [app] [I] Processing by
ForemanSalt::Api::V2::JobsController#upload as JSON
2016-03-31 06:32:10 [app] [I] Parameters:
{“job”=>{“function”=>“state.highstate”,

“result”=>{“wellminiondev.niwa.local”=>{“pkg_|-httpd_|-httpd_|-installed”=>{“comment”=>"Package

httpd is already installed", “name”=>“httpd”,
“start_time”=>“06:31:42.106300”, “result”=>true, “duration”=>2.279,
run_num”=>1, “changes”=>{}},
“pkg_|-nano_|-nano_|-installed”=>{“comment”=>“Package nano is already
installed”, “name”=>“nano”, “start_time”=>“06:31:41.098023”,
“result”=>true, “duration”=>1007.931, “run_num”=>0,
“changes”=>{}}}},
“job_id”=>“20160331063047033123”}, “apiv”=>“v2”}
2016-03-31 06:32:10 [app] [D] Verifying request from
[“wellkatellodev.niwa.local”] against [“wellkatellodev.niwa.local”]
2016-03-31 06:32:10 [app] [D] Setting current user thread-local
variable to
API Admin
2016-03-31 06:32:10 [app] [I] Processing job 20160331063047033123 from
Salt.
2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] ExecutionPlan
41e4ddb7-8ea1-496a-a91c-8ac41af03ba6 pending >> planning
2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] Step
41e4ddb7-8ea1-496a-a91c-8ac41af03ba6: 1 pending >> running in
phase
Plan Actions::ForemanSalt::ReportImport
2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] Step
41e4ddb7-8ea1-496a-a91c-8ac41af03ba6: 1 running >> success in
phase
Plan Actions::ForemanSalt::ReportImport
2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] ExecutionPlan
41e4ddb7-8ea1-496a-a91c-8ac41af03ba6 planning >> planned
2016-03-31 06:32:11 [app] [D] Body:
{“task_id”:“45e6aae0-a06b-4199-b27b-901e864ea244”}
2016-03-31 06:32:11 [app] [I] Completed 200 OK in 910ms (Views: 0.4ms

ActiveRecord: 282.6ms)
2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] ExecutionPlan
41e4ddb7-8ea1-496a-a91c-8ac41af03ba6 planned >> running
2016-03-31 06:32:11 [foreman-tasks/dynflow] [D] Step
41e4ddb7-8ea1-496a-a91c-8ac41af03ba6: 2 pending >> running in
phase
Run Actions::ForemanSalt::ReportImport
2016-03-31 06:32:11 [app] [D] Setting current user thread-local
variable to
Anonymous Admin
2016-03-31 06:32:12 [app] [I] processing report for
wellminiondev.niwa.local
2016-03-31 06:32:12 [app] [D] Report:
{“pkg_|-httpd_|-httpd_|-installed”=>{“comment”=>“Package httpd is
already
installed”, “name”=>“httpd”, “start_time”=>“06:31:42.106300”,
“result”=>true, “duration”=>2.279, “run_num”=>1, “changes”=>{}},
“pkg_|-nano_|-nano_|-installed”=>{“comment”=>“Package nano is already
installed”, “name”=>“nano”, “start_time”=>“06:31:41.098023”,
“result”=>true, “duration”=>1007.931, “run_num”=>0,
“changes”=>{}}}
2016-03-31 06:32:13 [app] [I] Imported report for
wellminiondev.niwa.local
in 0.77 seconds
2016-03-31 06:32:13 [foreman-tasks/dynflow] [D] Step
41e4ddb7-8ea1-496a-a91c-8ac41af03ba6: 2 running >> success in
phase
Run Actions::ForemanSalt::ReportImport
2016-03-31 06:32:13 [foreman-tasks/dynflow] [D] ExecutionPlan
41e4ddb7-8ea1-496a-a91c-8ac41af03ba6 running >> stopped

and here’s the /var/log/salt/master output for the same command

2016-03-31 06:30:47,174 [salt.loaded.int.module.cmdmod][INFO
][3294]
Executing command ‘/usr/bin/foreman-node wellminiondev.niwa.local’ in
directory ‘/root’
2016-03-31 06:31:13,591 [salt.loaded.int.module.cmdmod][ERROR
][3294]
Command ‘/usr/bin/foreman-node wellminiondev.niwa.local’ failed with
return
code: 1
2016-03-31 06:31:13,594 [salt.loaded.int.module.cmdmod][ERROR
][3294]
output: Couldn’t retrieve ENC data: execution expired
2016-03-31 06:31:13,596
[salt.loaded.int.pillar.puppet][CRITICAL][3294]
YAML data from /usr/bin/foreman-node failed to parse
2016-03-31 06:31:13,660 [salt.utils.lazy ][DEBUG ][3292] LazyLoaded
roots.envs
2016-03-31 06:31:40,102 [salt.loaded.int.top.ext_nodes][INFO
][3295]
master_tops ext_nodes call did not have a dictionary with a “classes”
key.
2016-03-31 06:31:41,689 [salt.config ][DEBUG ][3288] Reading
configuration from /etc/salt/master
2016-03-31 06:31:41,847 [salt.config ][DEBUG ][3288] Including
configuration from ‘/etc/salt/minion.d/schedule.conf’
2016-03-31 06:31:41,847 [salt.config ][DEBUG ][3288] Reading
configuration from /etc/salt/minion.d/schedule.conf
2016-03-31 06:31:41,851 [salt.config ][DEBUG ][3288] Using
cached
minion ID from /etc/salt/minion_id: wellkatellodev.niwa.local
2016-03-31 06:31:41,853 [salt.config ][DEBUG ][3288] Reading
configuration from /etc/salt/master
2016-03-31 06:31:42,215 [salt.utils.job ][INFO ][3291] Got return
from
wellminiondev.niwa.local for job 20160331063047033123
2016-03-31 06:31:42,215 [salt.utils.event ][DEBUG ][3291] Sending
event -
data = {‘fun_args’: [], ‘jid’: ‘20160331063047033123’, ‘return’:
{'pkg
|-httpd
|-httpd_|-installed’: {‘comment’: ‘Package httpd is
already
installed’, ‘name’: ‘httpd’, ‘start_time’: ‘06:31:42.106300’,
‘result’:
True, ‘duration’: 2.279, ‘run_num’: 1, ‘changes’: {}},
‘pkg_|-nano_|-nano_|-installed’: {‘comment’: ‘Package nano is already
installed’, ‘name’: ‘nano’, ‘start_time’: ‘06:31:41.098023’, ‘result’:
True, ‘duration’: 1007.931, ‘run_num’: 0, ‘changes’: {}}},
‘retcode’:
0, ‘success’: True, ‘cmd’: ‘_return’, ‘_stamp’:
‘2016-03-30T17:31:42.215041’, ‘fun’: ‘state.highstate’, ‘id’:
‘wellminiondev.niwa.local’, ‘out’: ‘highstate’}
2016-03-31 06:32:07,306 [salt.utils.lazy ][DEBUG ][3288] LazyLoaded
local_cache.clean_old_jobs
2016-03-31 06:32:07,319 [salt.utils.lazy ][DEBUG ][3288] Could not
LazyLoad config.merge
2016-03-31 06:32:07,320 [salt.fileserver ][DEBUG ][3288] Updating
roots
fileserver cache
2016-03-31 06:32:07,321 [salt.utils.verify][DEBUG ][3288] This
salt-master instance has accepted 2 minion keys.

Oh, if I change the host to wellkatellodev.niwa.local (the
katello/salt-master - i.e. localhost really) I get this still…

but in production.log

>
> Started GET "/node/wellkatellodev.niwa.local?format=yml" for
192.168.14.100 at 2016-03-31 08:27:26 +1300
2016-03-31 08:27:26 [app] [I] Processing by HostsController#externalNodes
as YML
2016-03-31 08:27:26 [app] [I] Parameters:
{"name"=>"wellkatellodev.niwa.local"}
2016-03-31 08:27:26 [app] [D] Verifying request from
["wellkatellodev.niwa.local"] against ["wellkatellodev.niwa.local"]
2016-03-31 08:27:26 [app] [D] Setting current user thread-local variable to
API Admin
2016-03-31 08:27:26 [app] [I] Rendered text template (0.0ms)
2016-03-31 08:27:26 [app] [I] Completed 200 OK in 98ms (Views: 0.7ms |
ActiveRecord: 12.0ms)
2016-03-31 08:27:28 [app] [I]
>
> Started POST "/api/hosts/facts" for 192.168.14.100 at 2016-03-31
08:27:28 +1300
2016-03-31 08:27:28 [app] [I] Processing by Api::V2::HostsController#facts
as JSON
2016-03-31 08:27:28 [app] [I] Parameters: {"facts"=>"[FILTERED]",
"name"=>"wellkatellodev.niwa.local",
"certname"=>"wellkatellodev.niwa.local", "apiv"=>"v2",
:host=>{"name"=>"wellkatellodev.niwa.local",
"certname"=>"wellkatellodev.niwa.local"}}
2016-03-31 08:27:28 [app] [D] Setting current location thread-local
variable to none
2016-03-31 08:27:28 [app] [D] Setting current organization thread-local
variable to none
2016-03-31 08:27:28 [app] [D] Importer Katello::RhsmFactImporter does not
implement authorized_smart_proxy_features.
2016-03-31 08:27:28 [app] [D] Verifying request from
["wellkatellodev.niwa.local"] against ["wellkatellodev.niwa.local"]
2016-03-31 08:27:28 [app] [D] Setting current user thread-local variable to
API Admin
2016-03-31 08:27:28 [app] [D] Merging facts for
'wellkatellodev.niwa.local': deleted 0 facts
2016-03-31 08:27:28 [app] [D] Merging facts for
'wellkatellodev.niwa.local': added 0 facts
2016-03-31 08:27:28 [app] [D] Merging facts for
'wellkatellodev.niwa.local': updated 7 facts
2016-03-31 08:27:28 [app] [I] Import facts for 'wellkatellodev.niwa.local'
completed. Added: 0, Updated: 7, Deleted 0 facts
2016-03-31 08:27:28 [app] [D] skipping interface with identifier 'lo' since
it was matched by 'ignored_interface_identifiers' setting
2016-03-31 08:27:28 [app] [D] We have following interfaces 'eno16780032'
based on facts
2016-03-31 08:27:28 [app] [D] Interface eno16780032 facts:
{"ipaddress"=>"192.168.14.100", "macaddress"=>"00:50:56:85:50:23",
"netmask"=>"255.255.255.0", "mtu"=>"1500", "network"=>"192.168.14.0"}
2016-03-31 08:27:28 [app] [D] Body:
{"architecture_id":1,"build":false,"certname":"wellkatellodev.niwa.local","comment":null,"compute_profile_id":null,"compute_resource_id":null,"content_source_id":null,"content_view_id":null,"created_at":"2016-03-03T21:11:37Z","discovery_rule_id":null,"disk":null,"enabled":true,"environment_id":1,"global_status":0,"grub_pass":"","hostgroup_id":null,"id":1,"image_file":"","image_id":null,"installed_at":null,"last_compile":"2016-03-30T19:27:28Z","last_report":"2016-03-30T18:57:25Z","lifecycle_environment_id":null,"location_id":24,"lookup_value_matcher":"fqdn=wellkatellodev.niwa.local","managed":false,"medium_id":null,"model_id":1,"name":"wellkatellodev.niwa.local","operatingsystem_id":1,"organization_id":6,"otp":null,"owner_id":null,"owner_type":null,"provision_method":"build","ptable_id":null,"puppet_ca_proxy_id":1,"puppet_proxy_id":1,"realm_id":null,"root_pass":null,"salt_environment_id":null,"salt_proxy_id":1,"updated_at":"2016-03-30T19:27:28Z","use_image":null,"uuid":null}
2016-03-31 08:27:28 [app] [I] Completed 201 Created in 180ms (Views: 7.1ms
> ActiveRecord: 0.0ms)
2016-03-31 08:27:28 [app] [I]
>
> Started GET "/node/wellkatellodev.niwa.local?format=yml" for
192.168.14.100 at 2016-03-31 08:27:28 +1300
2016-03-31 08:27:28 [app] [I] Processing by HostsController#externalNodes
as YML
2016-03-31 08:27:28 [app] [I] Parameters:
{"name"=>"wellkatellodev.niwa.local"}
2016-03-31 08:27:28 [app] [D] Verifying request from
["wellkatellodev.niwa.local"] against ["wellkatellodev.niwa.local"]
2016-03-31 08:27:28 [app] [D] Setting current user thread-local variable to
API Admin
2016-03-31 08:27:28 [app] [I] Rendered text template (0.0ms)
2016-03-31 08:27:28 [app] [I] Completed 200 OK in 146ms (Views: 1.2ms |
ActiveRecord: 17.0ms)
2016-03-31 08:27:29 [app] [I]
>
> Started POST "/api/reports" for 192.168.14.100 at 2016-03-31 08:27:29
+1300
2016-03-31 08:27:29 [app] [I] Processing by
Api::V2::ReportsController#create as JSON
2016-03-31 08:27:29 [app] [I] Parameters: {"report"=>"[FILTERED]",
"apiv"=>"v2"}
2016-03-31 08:27:29 [app] [D] Verifying request from
["wellkatellodev.niwa.local"] against ["wellkatellodev.niwa.local"]
2016-03-31 08:27:29 [app] [D] Setting current user thread-local variable to
API Admin
2016-03-31 08:27:29 [app] [I] processing report for
wellkatellodev.niwa.local
2016-03-31 08:27:29 [app] [D] Report: {"host"=>"wellkatellodev.niwa.local",
"reported_at"=>"2016-03-30 19:27:25 UTC", "status"=>{"applied"=>0,
"restarted"=>0, "failed"=>0, "failed_restarts"=>0, "skipped"=>0,
"pending"=>0}, "metrics"=>{"resources"=>{"changed"=>0, "failed"=>0,
"failed_to_restart"=>0, "out_of_sync"=>0, "restarted"=>0, "scheduled"=>0,
"skipped"=>0, "total"=>1}, "time"=>{"config_retrieval"=>0.957657252,
"filebucket"=>0.000147465, "total"=>0.9578047169999999},
"changes"=>{"total"=>0}, "events"=>{"failure"=>0, "success"=>0,
"total"=>0}}, "logs"=>[]}
2016-03-31 08:27:29 [app] [I] Imported report for wellkatellodev.niwa.local
in 0.02 seconds
2016-03-31 08:27:29 [app] [I] Rendered api/v2/reports/create.json.rabl
(7.0ms)
2016-03-31 08:27:29 [app] [D] Body:
{"metrics":{"resources":{"changed":0,"failed":0,"failed_to_restart":0,"out_of_sync":0,"restarted":0,"scheduled":0,"skipped":0,"total":1},"time":{"config_retrieval":0.957657252,"filebucket":0.000147465,"total":0.9578047169999999},"changes":{"total":0},"events":{"failure":0,"success":0,"total":0}},"created_at":"2016-03-30T19:27:29Z","updated_at":"2016-03-30T19:27:29Z","id":3024,"host_id":1,"host_name":"wellkatellodev.niwa.local","reported_at":"2016-03-30T19:27:25Z","status":{"applied":0,"restarted":0,"failed":0,"failed_restarts":0,"skipped":0,"pending":0},"logs":[],"summary":"Success"}
2016-03-31 08:27:29 [app] [I] Completed 201 Created in 50ms (Views: 7.1ms |
ActiveRecord: 9.2ms)

Note I hadn't set a salt environment for wellkatellodev at that point, so
did so, added the 'wget' salt state (which isn't specified in top.sls) and
re-ran foreman-node wellkatellodev.niwa.local -

[root@wellkatellodev ~]# /usr/bin/foreman-node wellkatellodev.niwa.local
Couldn't retrieve ENC data: execution expired

All I got in production.log this time is below

2016-03-31 08:30:12 [app] [I] Connecting to database specified by
database.yml
2016-03-31 08:30:12 [app] [I] Connecting to database specified by
database.yml
2016-03-31 08:30:45 [foreman-tasks/dynflow] [I] start terminating
throttle_limiter…
2016-03-31 08:30:45 [foreman-tasks/dynflow] [I] start terminating client
dispatcher…
2016-03-31 08:30:45 [foreman-tasks/dynflow] [I] stop listening for new
events…
2016-03-31 08:30:45 [foreman-tasks/dynflow] [I] start terminating clock…
2016-03-31 08:30:46 [foreman-tasks/dynflow] [I] start terminating
throttle_limiter…
2016-03-31 08:30:46 [foreman-tasks/dynflow] [I] start terminating client
dispatcher…
2016-03-31 08:30:46 [foreman-tasks/dynflow] [I] stop listening for new
events…
2016-03-31 08:30:46 [foreman-tasks/dynflow] [I] start terminating clock…

··· On Thursday, March 31, 2016 at 8:25:53 AM UTC+13, Dylan Baars wrote: > > For completeness - here's /etc/salt/foreman.yaml > > --- > :proto: https > :host: wellkatellodev.niwa.local > :port: 443 > :timeout: 10 > :salt: /usr/bin/salt > :upload_grains: true > :ssl_ca: "/etc/puppet/ssl_ca.pem" > :ssl_cert: "/etc/puppet/client_cert.pem" > :ssl_key: "/etc/puppet/client_key.pem" > > and running foreman-node > > [root@wellkatellodev ~]# /usr/bin/foreman-node wellminiondev.niwa.local > Couldn't retrieve ENC data: execution expired > [root@wellkatellodev ~]# > > nothing appeared in production.log at all. Just to prove I'm getting the > fqdn right - > > [root@wellkatellodev ~]# hammer host list > > ---|---------------------------|------------------|------------|----------------|------------------ > ID | NAME | OPERATING SYSTEM | HOST GROUP | IP > > MAC > > ---|---------------------------|------------------|------------|----------------|------------------ > 1 | wellkatellodev.niwa.local | CentOS 7.2 | | > 192.168.14.100 | 00:50:56:85:50:23 > 2 | wellminiondev.niwa.local | CentOS 7.2 | | > 192.168.14.102 | 00:50:56:85:14:ea > 3 | wellsaltdev.niwa.local | CentOS 7.2 | | > 192.168.14.101 | 00:50:56:85:76:19 > > ---|---------------------------|------------------|------------|----------------|------------------ > [root@wellkatellodev ~]# > > > > > On Thursday, March 31, 2016 at 8:18:22 AM UTC+13, stephen wrote: > > Sorry I take that back, I see the execution expired error in the salt logs > but not in the foreman. > > It'd be useful if you could still run foreman-node by itself and share the > production.log when you do. > > Also /etc/salt/foreman.yaml, if you've made any changes since the first > message. > > > ----- Original Message ----- > > From: "Stephen Benjamin" > > To: "Dylan Baars" > > Cc: "Foreman users" > > Sent: Wednesday, March 30, 2016 3:15:52 PM > > Subject: Re: [foreman-users] Importing salt states fails ERF12-4701 > > > > I don't see any errors here, it looks like Salt ran successfully, and > even > > uploaded a report to Foreman. > > > > Can you run `foreman-node fqdn` like in your other message, and share > the > > production.log if you still get an error? > > > > > > ----- Original Message ----- > > > From: "Dylan Baars" > > > To: "Foreman users" > > > Cc: ste...@redhat.com > > > Sent: Wednesday, March 30, 2016 1:40:58 PM > > > Subject: Re: [foreman-users] Importing salt states fails ERF12-4701 > > > > > > Morning, > > > > > > with debug logging for foreman enabled - edited > /etc/foreman/settings.yaml > > > > > > :logging: > > > # :level: info > > > :level: debug > > > > > > > > > this is what is output when I hit "Run Salt" in the GUI > > > > > > > Started GET "/salt/run/wellminiondev.niwa.local" for 192.168.81.51 > at > > > 2016-03-31 06:30:45 +1300 > > > 2016-03-31 06:30:45 [app] [I] Processing by > > > ForemanSalt::MinionsController#run as HTML > > > 2016-03-31 06:30:45 [app] [I] Parameters: > > > {"id"=>"wellminiondev.niwa.local"} > > > 2016-03-31 06:30:45 [app] [D] Setting current user thread-local > variable to > > > Dylan Baars > > > 2016-03-31 06:30:45 [app] [D] Setting current organization > thread-local > > > variable to NIWA > > > 2016-03-31 06:30:45 [app] [D] Setting current location thread-local > > > variable to none > > > 2016-03-31 06:30:47 [app] [I] Redirected to > > > https://wellkatellodev.niwa.local/hosts/wellminiondev.niwa.local > > > 2016-03-31 06:30:47 [app] [I] Completed 302 Found in 1288ms > (ActiveRecord: > > > 16.9ms) > > > 2016-03-31 06:30:47 [app] [I] > > > > > > > > Started GET "/hosts/wellminiondev.niwa.local" for 192.168.81.51 at > > > 2016-03-31 06:30:47 +1300 > > > 2016-03-31 06:30:47 [app] [I] Processing by HostsController#show as > HTML > > > 2016-03-31 06:30:47 [app] [I] Parameters: > > > {"id"=>"wellminiondev.niwa.local"} > > > 2016-03-31 06:30:47 [app] [D] Setting current user thread-local > variable to > > > Dylan Baars > > > 2016-03-31 06:30:47 [app] [D] Setting current organization > thread-local > > > variable to NIWA > > > 2016-03-31 06:30:47 [app] [D] Setting current location thread-local > > > variable to none > > > 2016-03-31 06:30:47 [app] [D] Deface: 1 overrides found for > 'hosts/show' > > > 2016-03-31 06:30:47 [app] [D] Deface: 'add_system_link_to_host' > matched 1 > > > times with 'td:first' > > > 2016-03-31 06:30:47 [app] [I] Deface: [WARNING] No :original defined > for > > > 'add_system_link_to_host', you should change its definition to > include: > > > > :original => '68201d5314be8a5aeb05b063bc5cd0afaf58a6c5' > > > 2016-03-31 06:30:48 [app] [I] Rendered hosts/_metrics.html.erb > (1.2ms) > > > 2016-03-31 06:30:48 [app] [I] Rendered hosts/show.html.erb within > > > layouts/application (948.3ms) > > > 2016-03-31 06:30:48 [app] [I] Rendered home/_user_dropdown.html.erb > > > (239.2ms) > > > 2016-03-31 06:30:48 [app] [I] Read fragment > views/tabs_and_title_records-4 > > > (0.3ms) > > > 2016-03-31 06:30:48 [app] [I] Rendered home/_topbar.html.erb > (242.4ms) > > > 2016-03-31 06:30:48 [app] [I] Rendered layouts/base.html.erb > (246.2ms) > > > 2016-03-31 06:30:48 [app] [I] Completed 200 OK in 1557ms (Views: > 1416.4ms | > > > ActiveRecord: 27.6ms) > > > 2016-03-31 06:30:49 [app] [I] > > > > > > > > Started GET "/hosts/wellminiondev.niwa.local/overview" for > 192.168.81.51 > > > at 2016-03-31 06:30:49 +1300 > > > 2016-03-31 06:30:49 [app] [I] Processing by HostsController#overview > as > > > HTML > > > 2016-03-31 06:30:49 [app] [I] Parameters: > > > {"id"=>"wellminiondev.niwa.local"} > > > 2016-03-31 06:30:49 [app] [D] Setting current user thread-local > variable to > > > Dylan Baars > > > 2016-03-31 06:30:49 [app] [D] Setting current organization > thread-local > > > variable to NIWA > > > 2016-03-31 06:30:49 [app] [D] Setting current location thread-local > > > variable to none > > > 2016-03-31 06:30:49 [app] [I] > > > > > > > > Started GET "/hosts/wellminiondev.niwa.local/nics" for > 192.168.81.51 at > > > 2016-03-31 06:30:49 +1300 > > > 2016-03-31 06:30:49 [app] [D] Deface: 1 overrides found for > > > 'hosts/_overview' > > > 2016-03-31 06:30:49 [app] [D] Deface: 'add_system_status_to_host' > matched 1 > > > times with 'tr:first-child' > > > 2016-03-31 06:30:49 [app] [I] Deface: [WARNING] No :original defined > for > > > 'add_system_status_to_host', you should change its definition to > include: > > > > :original => '68e6b32c550fbc7beca04e60b2851003b1f3afed' > > > 2016-03-31 06:30:49 [app] [I] Processing by HostsController#nics as > HTML > > > 2016-03-31 06:30:49 [app] [I] Parameters: > > > {"id"=>"wellminiondev.niwa.local"} > > > 2016-03-31 06:30:49 [app] [I] > > > > > > > > Started GET "/hosts/wellminiondev.niwa.local/resources?range=7" for > > > 192.168.81.51 at 2016-03-31 06:30:49 +1300 > > > 2016-03-31 06:30:49 [app] [D] Setting current user thread-local > variable to > > > Dylan Baars > > > 2016-03-31 06:30:49 [app] [I] > > > > > > > > Started GET "/hosts/wellminiondev.niwa.local/runtime?range=7" for > > > 192.168.81.51 at 2016-03-31 06:30:49 +1300 > > > 2016-03-31 06:30:49 [app] [D] Setting current organization > thread-local > > > variable to NIWA > > > 2016-03-31 06:30:49 [app] [D] Setting current location thread-local > > > variable to none > > > 2016-03-31 06:30:49 [app] [I] Processing by HostsController#runtime as > HTML > > > 2016-03-31 06:30:49 [app] [I] Parameters: {"range"=>"7", > > > "id"=>"wellminiondev.niwa.local"} > > > 2016-03-31 06:30:49 [app] [I] Processing by HostsController#resources > as > > > HTML > > > 2016-03-31 06:30:49 [app] [I] Parameters: {"range"=>"7", > > > "id"=>"wellminiondev.niwa.local"} > > > 2016-03-31 06:30:49 [app] [D] Setting current user thread-local > variable to > > > Dylan Baars > > > 2016-03-31 06:30:49 [app] [D] Setting current user thread-local > variable to > > > Dylan Baars > > > 2016-03-31 06:30:49 [app] [D] Setting current organization > thread-local > > > variable to NIWA > > > 2016-03-31 06:30:49 [app] [D] Setting current location thread-local > > > variable to none > > > 2016-03-31 06:30:49 [app] [I] Rendered hosts/_nics.html.erb (20.0ms) > > > 2016-03-31 06:30:49 [app] [I] Completed 200 OK in 69ms (Views: 11.3ms > > > > > ActiveRecord: 36.6ms) > > > 2016-03-31 06:30:49 [app] [D] Setting current organization > thread-local > > > variable to NIWA > > > 2016-03-31 06:30:49 [app] [D] Setting current location thread-local > > > variable to none > > > 2016-03-31 06:30:49 [app] [I] > > > > > > > > Started GET "/hosts/wellminiondev.niwa.local/templates" for > > > 192.168.81.51 at 2016-03-31 06:30:49 +1300 > > > 2016-03-31 06:30:50 [app] [I] Rendered hosts/_resources.html.erb > > > (320.1ms) > > > 2016-03-31 06:30:50 [app] [I] Completed 200 OK in 755ms (Views: > 714.7ms | > > > ActiveRecord: 19.3ms) > > > 2016-03-31 06:30:50 [app] [I] Rendered hosts/_overview.html.erb > (931.7ms) > > > 2016-03-31 06:30:50 [app] [I] Completed 200 OK in 974ms (Views: > 744.6ms | > > > ActiveRecord: 204.4ms) > > > 2016-03-31 06:30:50 [app] [I] Rendered hosts/_runtime.html.erb > (1339.7ms) > > > 2016-03-31 06:30:50 [app] [I] Completed 200 OK in 1415ms (Views: > 874.3ms | > > > ActiveRecord: 511.4ms) > > > 2016-03-31 06:30:51 [app] [I] Processing by HostsController#templates > as > > > HTML > > > 2016-03-31 06:30:51 [app] [I] Parameters: > > > {"id"=>"wellminiondev.niwa.local"} > > > 2016-03-31 06:30:51 [app] [D] Setting current user thread-local > variable to > > > Dylan Baars > > > 2016-03-31 06:30:51 [app] [D] Setting current organization > thread-local > > > variable to NIWA > > > 2016-03-31 06:30:51 [app] [D] Setting current location thread-local > > > variable to none > > > 2016-03-31 06:30:52 [app] [I] Rendered text temp

Found the problem - increased the timeout value in /etc/salt/foreman.yaml
from 10 to 60 - so that file now looks like

··· --- :proto: https :host: wellkatellodev.niwa.local :port: 443 :timeout: 60 :salt: /usr/bin/salt :upload_grains: true :ssl_ca: "/etc/puppet/ssl_ca.pem" :ssl_cert: "/etc/puppet/client_cert.pem" :ssl_key: "/etc/puppet/client_key.pem"

rebooted, and ran “Run salt” from the GUI - now the salt master log
/var/log/salt/master shows the foreman-node command working.

2016-03-31 09:17:36,100 [salt.loaded.int.module.cmdmod][INFO ][3314]
Executing command ‘/usr/bin/foreman-node wellminiondev.niwa.local’ in
directory ‘/root’
2016-03-31 09:17:36,558 [salt.utils.lazy ][DEBUG ][3300] LazyLoaded
local_cache.clean_old_jobs
2016-03-31 09:17:36,570 [salt.utils.lazy ][DEBUG ][3300] Could not
LazyLoad config.merge
2016-03-31 09:17:36,570 [salt.fileserver ][DEBUG ][3300] Updating roots
fileserver cache
2016-03-31 09:17:36,572 [salt.utils.verify][DEBUG ][3300] This
salt-master instance has accepted 2 minion keys.
2016-03-31 09:18:03,345 [salt.loaded.int.module.cmdmod][DEBUG ][3314]
output: —
classes:

  • wget
    parameters:
    puppetmaster: wellkatellodev.niwa.local
    organization: NIWA
    root_pw:
    puppet_ca: wellkatellodev.niwa.local
    foreman_env: production
    owner_name: Dylan Baars
    owner_email: removed
    foreman_subnets:
    foreman_interfaces:
    • mac: 00:50:56:85:14:ea
      ip: 192.168.14.102
      type: Interface
      name: wellminiondev.niwa.local
      attrs: {}
      virtual: false
      link: true
      identifier: eno16780032
      managed: true
      primary: true
      provision: true
      subnet:
      salt_master: wellkatellodev.niwa.local
      kt_env:
      kt_cv:
      lifecycle_environment:
      content_view:
      environment: base
      2016-03-31 09:18:03,418 [salt.utils.lazy ][DEBUG ][3310] LazyLoaded
      roots.envs
      2016-03-31 09:18:29,929 [salt.utils.lazy ][DEBUG ][3313] LazyLoaded
      roots.envs
      2016-03-31 09:18:32,121 [salt.utils.job ][INFO ][3313] Got return from
      wellminiondev.niwa.local for job 20160331091735908119
      2016-03-31 09:18:32,122 [salt.utils.event ][DEBUG ][3313] Sending event -
      data = {‘fun_args’: , ‘jid’: ‘20160331091735908119’, ‘return’:
      {‘pkg_|-wget_|-wget_|-installed’: {‘comment’: ‘Package wget is already
      installed’, ‘name’: ‘wget’, ‘start_time’: ‘09:18:31.027404’, ‘result’:
      True, ‘duration’: 983.601, ‘run_num’: 0, ‘changes’: {}},
      ‘pkg_|-httpd_|-httpd_|-installed’: {‘comment’: ‘Package httpd is already
      installed’, ‘name’: ‘httpd’, ‘start_time’: ‘09:18:32.011344’, ‘result’:
      True, ‘duration’: 2.162, ‘run_num’: 1, ‘changes’: {}},
      ‘pkg_|-nano_|-nano_|-installed’: {‘comment’: ‘Package nano is already
      installed’, ‘name’: ‘nano’, ‘start_time’: ‘09:18:32.013822’, ‘result’:
      True, ‘duration’: 1.076, ‘run_num’: 2, ‘changes’: {}}}, ‘retcode’: 0,
      ‘success’: True, ‘cmd’: ‘_return’, ‘_stamp’: ‘2016-03-30T20:18:32.121902’,
      ‘fun’: ‘state.highstate’, ‘id’: ‘wellminiondev.niwa.local’, ‘out’:
      ‘highstate’}
      2016-03-31 09:18:36,632 [salt.config ][DEBUG ][3300] Reading
      configuration from /etc/salt/master

On the minion /var/log/salt/minion

2016-03-31 09:18:31,027 [salt.state ][INFO ][29598] Running state
[wget] at time 09:18:31.027404
2016-03-31 09:18:31,028 [salt.state ][INFO ][29598] Executing
state pkg.installed for wget
2016-03-31 09:18:31,029 [salt.loaded.int.module.cmdmod][INFO ][29598]
Executing command [‘rpm’, ‘-qa’, ‘–queryformat’,
‘%{NAME}|-%{EPOCH}|-%{VERSION}|-%{RELEASE}|-%{ARCH}_|-(none)\n’] in
directory ‘/root’
2016-03-31 09:18:32,011 [salt.state ][INFO ][29598] Package wget
is already installed
2016-03-31 09:18:32,011 [salt.state ][INFO ][29598] Completed
state [wget] at time 09:18:32.011005

and in the foreman/katello GUI if I browse reports for that host
(wellminiondev) I see all 3 state files are applied (2 via top.sls, 1 via
foreman association). The VM may be under-powered (4vcpu, 6gb ram) for
running Katello and Salt, so that may be the cause of the timeout

Finally, running foreman-node manually works as well

[root@wellkatellodev foreman]# /usr/bin/foreman-node
wellminiondev.niwa.local

classes:

  • wget
    parameters:
    puppetmaster: wellkatellodev.niwa.local
    organization: NIWA
    root_pw:
    puppet_ca: wellkatellodev.niwa.local
    foreman_env: production
    owner_name: Dylan Baars
    owner_email: removed
    foreman_subnets:
    foreman_interfaces:
    • mac: 00:50:56:85:14:ea
      ip: 192.168.14.102
      type: Interface
      name: wellminiondev.niwa.local
      attrs: {}
      virtual: false
      link: true
      identifier: eno16780032
      managed: true
      primary: true
      provision: true
      subnet:
      salt_master: wellkatellodev.niwa.local
      kt_env:
      kt_cv:
      lifecycle_environment:
      content_view:
      environment: base
      [root@wellkatellodev foreman]#

Magic thanks heaps for your help!

Dylan

On Thursday, March 31, 2016 at 8:33:09 AM UTC+13, Dylan Baars wrote:
Oh, if I change the host to wellkatellodev.niwa.local (the
katello/salt-master - i.e. localhost really) I get this still…

but in production.log

Started GET “/node/wellkatellodev.niwa.local?format=yml” for
192.168.14.100 at 2016-03-31 08:27:26 +1300
2016-03-31 08:27:26 [app] [I] Processing by HostsController#externalNodes
as YML
2016-03-31 08:27:26 [app] [I] Parameters:
{“name”=>“wellkatellodev.niwa.local”}
2016-03-31 08:27:26 [app] [D] Verifying request from
[“wellkatellodev.niwa.local”] against [“wellkatellodev.niwa.local”]
2016-03-31 08:27:26 [app] [D] Setting current user thread-local variable to
API Admin
2016-03-31 08:27:26 [app] [I] Rendered text template (0.0ms)
2016-03-31 08:27:26 [app] [I] Completed 200 OK in 98ms (Views: 0.7ms |
ActiveRecord: 12.0ms)
2016-03-31 08:27:28 [app] [I]

Started POST “/api/hosts/facts” for 192.168.14.100 at 2016-03-31
08:27:28 +1300
2016-03-31 08:27:28 [app] [I] Processing by Api::V2::HostsController#facts
as JSON
2016-03-31 08:27:28 [app] [I] Parameters: {“facts”=>“[FILTERED]”,
“name”=>“wellkatellodev.niwa.local”,
“certname”=>“wellkatellodev.niwa.local”, “apiv”=>“v2”,
:host=>{“name”=>“wellkatellodev.niwa.local”,
“certname”=>“wellkatellodev.niwa.local”}}
2016-03-31 08:27:28 [app] [D] Setting current location thread-local
variable to none
2016-03-31 08:27:28 [app] [D] Setting current organization thread-local
variable to none
2016-03-31 08:27:28 [app] [D] Importer Katello::RhsmFactImporter does not
implement authorized_smart_proxy_features.
2016-03-31 08:27:28 [app] [D] Verifying request from
[“wellkatellodev.niwa.local”] against [“wellkatellodev.niwa.local”]
2016-03-31 08:27:28 [app] [D] Setting current user thread-local variable to
API Admin
2016-03-31 08:27:28 [app] [D] Merging facts for
‘wellkatellodev.niwa.local’: deleted 0 facts
2016-03-31 08:27:28 [app] [D] Merging facts for
‘wellkatellodev.niwa.local’: added 0 facts
2016-03-31 08:27:28 [app] [D] Merging facts for
‘wellkatellodev.niwa.local’: updated 7 facts
2016-03-31 08:27:28 [app] [I] Import facts for ‘wellkatellodev.niwa.local’
completed. Added: 0, Updated: 7, Deleted 0 facts
2016-03-31 08:27:28 [app] [D] skipping interface with identifier ‘lo’ since
it was matched by ‘ignored_interface_identifiers’ setting
2016-03-31 08:27:28 [app] [D] We have following interfaces ‘eno16780032’
based on facts
2016-03-31 08:27:28 [app] [D] Interface eno16780032 facts:
{“ipaddress”=>“192.168.14.100”, “macaddress”=>“00:50:56:85:50:23”,
“netmask”=>“255.255.255.0”, “mtu”=>“1500”, “network”=>“192.168.14.0”}
2016-03-31 08:27:28 [app] [D] Body:
{“architecture_id”:1,“build”:false,“certname”:“wellkatellodev.niwa.local”,“comment”:null,“compute_profile_id”:null,“compute_resource_id”:null,“content_source_id”:null,“content_view_id”:null,“created_at”:“2016-03-03T21:11:37Z”,“discovery_rule_id”:null,“disk”:null,“enabled”:true,“environment_id”:1,“global_status”:0,“grub_pass”:“”,“hostgroup_id”:null,“id”:1,“image_file”:“”,“image_id”:null,“installed_at”:null,“last_compile”:“2016-03-30T19:27:28Z”,“last_report”:“2016-03-30T18:57:25Z”,“lifecycle_environment_id”:null,“location_id”:24,“lookup_value_matcher”:“fqdn=wellkatellodev.niwa.local”,“managed”:false,“medium_id”:null,“model_id”:1,“name”:“wellkatellodev.niwa.local”,“operatingsystem_id”:1,“organization_id”:6,“otp”:null,“owner_id”:null,“owner_type”:null,“provision_method”:“build”,“ptable_id”:null,“puppet_ca_proxy_id”:1,“puppet_proxy_id”:1,“realm_id”:null,“root_pass”:null,“salt_environment_id”:null,“salt_proxy_id”:1,“updated_at”:“2016-03-30T19:27:28Z”,“use_image”:null,“uuid”:null}
2016-03-31 08:27:28 [app] [I] Completed 201 Created in 180ms (Views: 7.1ms
ActiveRecord: 0.0ms)
2016-03-31 08:27:28 [app] [I]

Started GET “/node/wellkatellodev.niwa.local?format=yml” for
192.168.14.100 at 2016-03-31 08:27:28 +1300
2016-03-31 08:27:28 [app] [I] Processing by HostsController#externalNodes
as YML
2016-03-31 08:27:28 [app] [I] Parameters:
{“name”=>“wellkatellodev.niwa.local”}
2016-03-31 08:27:28 [app] [D] Verifying request from
[“wellkatellodev.niwa.local”] against [“wellkatellodev.niwa.local”]
2016-03-31 08:27:28 [app] [D] Setting current user thread-local variable to
API Admin
2016-03-31 08:27:28 [app] [I] Rendered text template (0.0ms)
2016-03-31 08:27:28 [app] [I] Completed 200 OK in 146ms (Views: 1.2ms |
ActiveRecord: 17.0ms)
2016-03-31 08:27:29 [app] [I]

Started POST “/api/reports” for 192.168.14.100 at 2016-03-31 08:27:29
+1300
2016-03-31 08:27:29 [app] [I] Processing by
Api::V2::ReportsController#create as JSON
2016-03-31 08:27:29 [app] [I] Parameters: {“report”=>“[FILTERED]”,
“apiv”=>“v2”}
2016-03-31 08:27:29 [app] [D] Verifying request from
[“wellkatellodev.niwa.local”] against [“wellkatellodev.niwa.local”]
2016-03-31 08:27:29 [app] [D] Setting current user thread-local variable to
API Admin
2016-03-31 08:27:29 [app] [I] processing report for
wellkatellodev.niwa.local
2016-03-31 08:27:29 [app] [D] Report: {“host”=>“wellkatellodev.niwa.local”,
“reported_at”=>“2016-03-30 19:27:25 UTC”, “status”=>{“applied”=>0,
“restarted”=>0, “failed”=>0, “failed_restarts”=>0, “skipped”=>0,
“pending”=>0}, “metrics”=>{“resources”=>{“changed”=>0, “failed”=>0,
“failed_to_restart”=>0, “out_of_sync”=>0, “restarted”=>0, “scheduled”=>0,
“skipped”=>0, “total”=>1}, “time”=>{“config_retrieval”=>0.957657252,
“filebucket”=>0.000147465, “total”=>0.9578047169999999},
“changes”=>{“total”=>0}, “events”=>{“failure”=>0, “success”=>0,
“total”=>0}}, “logs”=>}
2016-03-31 08:27:29 [app] [I] Imported report for wellkatellodev.niwa.local
in 0.02 seconds
2016-03-31 08:27:29 [app] [I] Rendered api/v2/reports/create.json.rabl
(7.0ms)
2016-03-31 08:27:29 [app] [D] Body:
{“metrics”:{“resources”:{“changed”:0,“failed”:0,“failed_to_restart”:0,“out_of_sync”:0,“restarted”:0,“scheduled”:0,“skipped”:0,“total”:1},“time”:{“config_retrieval”:0.957657252,“filebucket”:0.000147465,“total”:0.9578047169999999},“changes”:{“total”:0},“events”:{“failure”:0,“success”:0,“total”:0}},“created_at”:“2016-03-30T19:27:29Z”,“updated_at”:“2016-03-30T19:27:29Z”,“id”:3024,“host_id”:1,“host_name”:“wellkatellodev.niwa.local”,“reported_at”:“2016-03-30T19:27:25Z”,“status”:{“applied”:0,“restarted”:0,“failed”:0,“failed_restarts”:0,“skipped”:0,“pending”:0},“logs”:,“summary”:“Success”}
2016-03-31 08:27:29 [app] [I] Completed 201 Created in 50ms (Views: 7.1ms |
ActiveRecord: 9.2ms)

Note I hadn’t set a salt environment for wellkatellodev at that point, so
did so, added the ‘wget’ salt state (which isn’t specified in top.sls) and
re-ran foreman-node wellkatellodev.niwa.local -

[root@wellkatellodev ~]# /usr/bin/foreman-node wellkatellodev.niwa.local
Couldn’t retrieve ENC data: execution expired

All I got in production.log this time is below

2016-03-31 08:30:12 [app] [I] Connecting to database specified by
database.yml
2016-03-31 08:30:12 [app] [I] Connecting to database specified by
database.yml
2016-03-31 08:30:45 [foreman-tasks/dynflow] [I] start terminating
throttle_limiter…
2016-03-31 08:30:45 [foreman-tasks/dynflow] [I] start terminating client
dispatcher…
2016-03-31 08:30:45 [foreman-tasks/dynflow] [I] stop listening for new
events…
2016-03-31 08:30:45 [foreman-tasks/dynflow] [I] start terminating clock…
2016-03-31 08:30:46 [foreman-tasks/dynflow] [I] start terminating
throttle_limiter…
2016-03-31 08:30:46 [foreman-tasks/dynflow] [I] start terminating client
dispatcher…
2016-03-31 08:30:46 [foreman-tasks/dynflow] [I] stop listening for new
events…
2016-03-31 08:30:46 [foreman-tasks/dynflow] [I] start terminating clock…

On Thursday, March 31, 2016 at 8:25:53 AM UTC+13, Dylan Baars wrote:
For completeness - here’s /etc/salt/foreman.yaml


:proto: https
:host: wellkatellodev.niwa.local
:port: 443
:timeout: 10
:salt: /usr/bin/salt
:upload_grains: true
:ssl_ca: “/etc/puppet/ssl_ca.pem”
:ssl_cert: “/etc/puppet/client_cert.pem”
:ssl_key: “/etc/puppet/client_key.pem”

and running foreman-node

[root@wellkatellodev ~]# /usr/bin/foreman-node wellminiondev.niwa.local
Couldn’t retrieve ENC data: execution expired
[root@wellkatellodev ~]#

nothing appeared in production.log at all. Just to prove I’m getting the
fqdn right -

[root@wellkatellodev ~]# hammer host list
—|---------------------------|------------------|------------|----------------|------------------
ID | NAME | OPERATING SYSTEM | HOST GROUP | IP
> MAC
—|---------------------------|------------------|------------|----------------|------------------
1 | wellkatellodev.niwa.local | CentOS 7.2 | |
192.168.14.100 | 00:50:56:85:50:23
2 | wellminiondev.niwa.local | CentOS 7.2 | |
192.168.14.102 | 00:50:56:85:14:ea
3 | wellsaltdev.niwa.local | CentOS 7.2 | |
192.168.14.101 | 00:50:56:85:76:19
—|---------------------------|------------------|------------|----------------|------------------
[root@wellkatellodev ~]#

On Thursday, March 31, 2016 at 8:18:22 AM UTC+13, stephen wrote:
Sorry I take that back, I see the execution expired error in the salt logs
but not in the foreman.

It’d be useful if you could still run foreman-node by itself and share the
production.log when you do.

Also /etc/salt/foreman.yaml, if you’ve made any changes since the first
message.

----- Original Message -----

From: “Stephen Benjamin” ste...@redhat.com
To: “Dylan Baars” baa...@gmail.com
Cc: “Foreman users” forema...@googlegroups.com
Sent: Wednesday, March 30, 2016 3:15:52 PM
Subject: Re: [foreman-users] Importing salt states fails ERF12-4701

I don’t see any errors here, it looks like Salt ran successfully, and
even
uploaded a report to Foreman.

Can you run foreman-node fqdn like in your other message, and share the
production.log if you still get an error?

----- Original Message -----

From: “Dylan Baars” baa...@gmail.com
To: “Foreman users” forema...@googlegroups.com
Cc: ste...@redhat.com
Sent: Wednesday, March 30, 2016 1:40:58 PM
Subject: Re: [foreman-users] Importing salt states fails ERF12-4701

Morning,

with debug logging for foreman enabled - edited
/etc/foreman/settings.yaml

:logging:

:level: info

:level: debug

this is what is output when I hit “Run Salt” in the GUI

Started GET “/salt/run/wellminiondev.niwa.local” for 192.168.81.51
at
2016-03-31 06:30:45 +1300
2016-03-31 06:30:45 [app] [I] Processing by
ForemanSalt::MinionsController#run as HTML
2016-03-31 06:30:45 [app] [I] Parameters:
{“id”=>“wellminiondev.niwa.local”}
2016-03-31 06:30:45 [app] [D] Setting current user thread-local
variable to
Dylan Baars
2016-03-31 06:30:45 [app] [D] Setting current organization thread-local
variable to NIWA
2016-03-31 06:30:45 [app] [D] Setting current location thread-local
variable to none
2016-03-31 06:30:47 [app] [I] Redirected to
https://wellkatellodev.niwa.local/hosts/wellminiondev.niwa.local
2016-03-31 06:30:47 [app] [I] Completed 302 Found in 1288ms
(ActiveRecord:
16.9ms)
2016-03-31 06:30:47 [app] [I]

Started GET “/hosts/wellminiondev.niwa.local” for 192.168.81.51 at
2016-03-31 06:30:47 +1300
2016-03-31 06:30:47 [app] [I] Processing by HostsController#show as
HTML
2016-03-31 06:30:47 [app] [I] Parameters:
{“id”=>“wellminiondev.niwa.local”}
2016-03-31 06:30:47 [app] [D] Setting current user thread-local
variable to
Dylan Baars
2016-03-31 06:30:47 [app] [D] Setting current organization thread-local
variable to NIWA
2016-03-31 06:30:47 [app] [D] Setting current location thread-local
variable to none
2016-03-31 06:30:47 [app] [D] Deface: 1 overrides found for
‘hosts/show’
2016-03-31 06:30:47 [app] [D] Deface: ‘add_system_link_to_host’ matched
1
times with ‘td:first’
2016-03-31 06:30:47 [app] [I] Deface: [WARNING] No :original defined
for
‘add_system_link_to_host’, you should change its definition to include:
:original => ‘68201d5314be8a5aeb05b063bc5cd0afaf58a6c5’
2016-03-31 06:30:48 [app] [I] Rendered hosts/_metrics.html.erb
(1.2ms)
2016-03-31 06:30:48 [app] [I] Rendered hosts/show.html.erb within
layouts/application (948.3ms)
2016-03-31 06:30:48 [app] [I] Rendered home/_user_dropdown.html.erb
(239.2ms)
2016-03-31 06:30:48 [app] [I] Read fragment
views/tabs_and_title_records-4
(0.3ms)
2016-03-31 06:30:48 [app] [I] Rendered home/_topbar.html.erb
(242.4ms)
2016-03-31 06:30:48 [app] [I] Rendered layouts/base.html.erb
(246.2ms)
2016-03-31 06:30:48 [app] [I] Completed 200 OK in 1557ms (Views:
1416.4ms |
ActiveRecord: 27.6ms)
2016-03-31 06:30:49 [app] [I]

Started GET "/hosts/wellminiondev.niwa.local/overvie