Foreman 1.10.1 : Problem with facts upload

Hello all,

Trying to troubleshoot a problem with Foreman 1.10.1 and uploading facts from host

Upload of facts from host to Foreman is working < only the first time >, when I validate a new host certificate on Foreman web UI. After that, there is no more facts updates.
Exception : All is working fine for the local server facts (= for the server hosting foreman).

The error is : ActiveRecord::RecordInvalid: Validation failed: Fact name has already been taken

production.log when trying to upload facts :

2016-02-08 14:00:15 [app] [I]
>
> Started POST "/api/hosts/facts" for 10.0.19.50 at 2016-02-08 14:00:15 +0100
2016-02-08 14:00:15 [app] [I] Processing by Api::V2::HostsController#facts as JSON
2016-02-08 14:00:15 [app] [I] Parameters: {"facts"=>"[FILTERED]", "name"=>"lslpput02.mydomain.com", "certname"=>"lslpput02.mydomain.com", "apiv"=>"v2", :host=>{"name"=>"lslpput02.mydomain.com", "certname"=>"lslpput02.mydomain.com"}}
2016-02-08 14:00:15 [app] [W] Action failed
> ActiveRecord::RecordInvalid: Validation failed: Fact name has already been taken
> /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/validations.rb:56:in save!&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/attribute_methods/dirty.rb:33:insave!'
> /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:246:in block in save!&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:295:inblock in with_transaction_returning_status'
> /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/connection_adapters/abstract/database_statements.rb:192:in transaction&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:208:intransaction'
> /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:293:in with_transaction_returning_status&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:246:insave!'
> /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/associations/has_many_association.rb:14:in insert_record&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/associations/collection_association.rb:434:inblock (2 levels) in create_record'
> /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/associations/collection_association.rb:342:in add_to_target&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/associations/collection_association.rb:432:inblock in create_record'
> /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/associations/collection_association.rb:149:in block in transaction&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/connection_adapters/abstract/database_statements.rb:192:intransaction'
> /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:208:in transaction&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/associations/collection_association.rb:148:intransaction'
> /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/associations/collection_association.rb:431:in create_record&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/associations/collection_association.rb:123:increate!'
> /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/associations/collection_proxy.rb:46:in create!&#39; &gt; /usr/share/foreman/app/services/fact_importer.rb:68:inblock in add_new_facts'
> /usr/share/foreman/app/services/fact_importer.rb:67:in each&#39; &gt; /usr/share/foreman/app/services/fact_importer.rb:67:inadd_new_facts'
> /usr/share/foreman/app/services/fact_importer.rb:36:in import!&#39; &gt; /usr/share/foreman/app/models/host/base.rb:121:inimport_facts'
> /usr/share/foreman/app/models/host/managed.rb:516:in import_host_and_facts&#39; &gt; /usr/share/foreman/app/controllers/api/v2/hosts_controller.rb:229:infacts'
> /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; /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&#39; &gt; /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:518:in block (5 levels) in _run__3026391986581779854__process_action__3851232205623071956__callbacks&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:inblock in _conditional_callback_around_12396'
> /usr/share/foreman/app/controllers/api/v2/base_controller.rb:151:in disable_json_root&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in_conditional_callback_around_12396'
> /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:495:in block (4 levels) in _run__3026391986581779854__process_action__3851232205623071956__callbacks&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:inblock in _conditional_callback_around_12395'
> /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:326:in around&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:310:in_callback_around_4179'
> /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in _conditional_callback_around_12395&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:483:inblock (3 levels) in _run__3026391986581779854__process_action__3851232205623071956__callbacks'
> /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in block in _conditional_callback_around_12394&#39; &gt; /usr/share/foreman/app/controllers/concerns/application_shared.rb:13:inset_timezone'
> /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in _conditional_callback_around_12394&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:482:inblock (2 levels) in _run__3026391986581779854__process_action__3851232205623071956__callbacks'
> /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in block in _conditional_callback_around_12393&#39; &gt; /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:inclear_thread'
> /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in _conditional_callback_around_12393&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:437:inblock in _run__3026391986581779854__process_action__3851232205623071956__callbacks'
> /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in block in _conditional_callback_around_12392&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:326:inaround'
> /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:310:in _callback_around_13&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in_conditional_callback_around_12392'
> /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:403:in _run__3026391986581779854__process_action__3851232205623071956__callbacks&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in__run_callback'
> /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in _run_process_action_callbacks&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:inrun_callbacks'
> /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/callbacks.rb:17:in process_action&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rescue.rb:29:inprocess_action'
> /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:30:in block in process_action&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:inblock in instrument'
> /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications/instrumenter.rb:20:in instrument&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:ininstrument'
> /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:29:in process_action&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/params_wrapper.rb:207:inprocess_action'
> /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/railties/controller_runtime.rb:18:in process_action&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/base.rb:121:inprocess'
> /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/rendering.rb:45:in process&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal.rb:203:indispatch'
> /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rack_delegation.rb:14:in dispatch&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal.rb:246:inblock in action'
> /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:73:in call&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:73:indispatch'
> /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:36:in call&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/mapper.rb:42:incall'
> /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:68:in block in call&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:ineach'
> /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in call&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:600:incall'
> /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in call&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:incall'
> /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.2.6/lib/apipie/extractor/recorder.rb:97:in call&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:incall'
> /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in call&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:incall'
> /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in call&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:incall'
> /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.2.6/lib/apipie/middleware/checksum_in_headers.rb:27:in call&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/best_standards_support.rb:17:incall'
> /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/etag.rb:23:in call&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/conditionalget.rb:35:incall'
> /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/head.rb:14:in call&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/params_parser.rb:21:incall'
> /usr/share/foreman/lib/middleware/catch_json_parse_errors.rb:9:in call&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/flash.rb:242:incall'
> /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:205:in context&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:200:incall'
> /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/cookies.rb:339:in call&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/query_cache.rb:64:incall'
> /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/connection_adapters/abstract/connection_pool.rb:473:in call&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:28:inblock in call'
> /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in _run__3465221670514608859__call__821409028543683544__callbacks&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in__run_callback'
> /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in _run_call_callbacks&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:inrun_callbacks'
> /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:27:in call&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/remote_ip.rb:31:incall'
> /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/debug_exceptions.rb:16:in call&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/show_exceptions.rb:56:incall'
> /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:26:in call_app&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:16:incall'
> /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/request_id.rb:22:in call&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/methodoverride.rb:21:incall'
> /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/runtime.rb:17:in call&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/cache/strategy/local_cache.rb:72:incall'
> /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/lock.rb:15:in call&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:incall'
> /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:136:in forward&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:143:inpass'
> /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:155:in invalidate&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:71:incall!'
> /opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:51:in call&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/engine.rb:479:incall'
> /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/application.rb:223:in call&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/railtie/configurable.rb:30:inmethod_missing'
> /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/builder.rb:134:in call&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/urlmap.rb:64:inblock in call'
> /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/urlmap.rb:49:in each&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/urlmap.rb:49:incall'
> /usr/share/gems/gems/passenger-4.0.18/lib/phusion_passenger/rack/thread_handler_extension.rb:77:in process_request&#39; &gt; /usr/share/gems/gems/passenger-4.0.18/lib/phusion_passenger/request_handler/thread_handler.rb:140:inaccept_and_process_next_request'
> /usr/share/gems/gems/passenger-4.0.18/lib/phusion_passenger/request_handler/thread_handler.rb:108:in main_loop&#39; &gt; /usr/share/gems/gems/passenger-4.0.18/lib/phusion_passenger/request_handler.rb:441:inblock (3 levels) in start_threads'
> /opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in call&#39; &gt; /opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:inblock in create_with_logging_context'
2016-02-08 14:00:15 [app] [I] Rendered api/v2/errors/standard_error.json.rabl within api/v2/layouts/error_layout (0.7ms)
2016-02-08 14:00:15 [app] [I] Comple

>
> Hello all,
>
> Trying to troubleshoot a problem with Foreman 1.10.1 and uploading facts
from host
>
> Upload of facts from host to Foreman is working « only the first time »,
when I validate a new host certificate on Foreman web UI. After that, there
is no more facts updates.
>
> Exception : All is working fine for the local server facts (= for the
server hosting foreman).
>
> The error is : ActiveRecord::RecordInvalid: Validation failed: Fact name
has already been taken
>
> production.log when trying to upload facts :
>
> 2016-02-08 14:00:15 [app] [I] Started POST "/api/hosts/facts" for
10.0.19.50 at 2016-02-08 14:00:15 +0100
> 2016-02-08 14:00:15 [app] [I] Processing by
Api::V2::HostsController#facts as JSON
> 2016-02-08 14:00:15 [app] [I] Parameters: {"facts"=>"[FILTERED]",
"name"=>"lslpput02.mydomain.com", "certname"=>"lslpput02.mydomain.com",
"apiv"=>"v2", :host=>{"name"=>"lslpput02.mydomain.com", "certname"=>"
lslpput02.mydomain.com"}}
> 2016-02-08 14:00:15 [app] [W] Action failed |
ActiveRecord::RecordInvalid: Validation failed: Fact name has already been
taken
>
> Any idea ?
>
> My ideas are cert problems, or firewall problems (but host reports to
foreman are OK…), or http proxy ( ??..) problems. But i’ve no idea how to
troubleshoot…

This is not a network issue - the logs above show Foreman receiving the
facts and then aborting due to an issue with the contained data. Do you
have any custom facts or other odd fact data that might cause issues?

Greg

··· On 8 February 2016 at 13:44, Pulfer Pierre-Alain < Pierre-Alain.Pulfer@lausanne.ch> wrote:

Folks,

We're experiencing the same thing where I am. We do have some custom
facts, and were looking to see what might be causing the breakage.

I put a logger.info statement into that file
(/usr/share/foreman/app/services/fact_importer.rb) so, it looked like this:
def add_new_facts
facts_to_create = facts.keys - db_facts.keys
# if the host does not exists yet, we don't have an host_id to use the
fact_values table.
if facts_to_create.present?
method = host.new_record? ? :build : :create!
fact_names = fact_name_class.group(:name).maximum(:id)
facts_to_create.each do |name|
logger.info("facts_to_create called for fact '#{name}'")
host.fact_values.send(method, :value => facts[name],
:fact_name_id => fact_names[name] ||
fact_name_class.create!(:name => name).id)
end
end

@counters[:added] = facts_to_create.size
logger.debug(&quot;Merging facts for &#39;#{host}&#39;: added #{@counters[:added]} 

facts")
end

I restarted katello-services after changing the logging settings in
/etc/foreman/logging.yaml to:

:production:
:filename: "production.log"
:level: debug
:colorize: true
:console_inline: true

Note: this is a development environment that we regularly re-build as we
work on this project.

The result was:

2016-04-20 20:19:49 [app] [I] facts_to_create called for fact '_timestamp'
2016-04-20 20:19:49 [app] [W] Action failed
> ActiveRecord::RecordInvalid: Validation failed: Fact name has already
been taken

When I looked through the YAML file on the host, it had this fact in it:
"_timestamp": 2016-04-20 20:19:48.685814 +00:00

So, I presume the quoted _timestamp fact is what is causing it to puke.
I'll have to dig through to see where this is coming from. Just thought
I'd post the process I used to figure it out. Maybe that'll help those
that are still having this problem. Now, I'm off to figure out where that
fact is coming from…

Cheers!

/Mike

··· On Monday, February 8, 2016 at 8:52:01 AM UTC-5, Pulfer Pierre-Alain wrote: > > Hello all, > > > > Trying to troubleshoot a problem with Foreman 1.10.1 and uploading facts > from host > > > > Upload of facts from host to Foreman is working « only the first time », > when I validate a new host certificate on Foreman web UI. After that, > there is no more facts updates. > > Exception : All is working fine for the local server facts (= for the > server hosting foreman). > > > > The error is : ActiveRecord::RecordInvalid: Validation failed: Fact name > has already been taken > > > > production.log when trying to upload facts : > > > > 2016-02-08 14:00:15 [app] [I] > > > > > > Started POST "/api/hosts/facts" for 10.0.19.50 at 2016-02-08 14:00:15 > +0100 > > 2016-02-08 14:00:15 [app] [I] Processing by Api::V2::HostsController#facts > as JSON > > 2016-02-08 14:00:15 [app] [I] Parameters: {"facts"=>"[FILTERED]", > "name"=>"lslpput02.mydomain.com", "certname"=>"lslpput02.mydomain.com", > "apiv"=>"v2", :host=>{"name"=>"lslpput02.mydomain.com", "certname"=>" > lslpput02.mydomain.com"}} > > 2016-02-08 14:00:15 [app] [W] Action failed > > > ActiveRecord::RecordInvalid: Validation failed: Fact name has already > been taken > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/validations.rb:56:in > `save!' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/attribute_methods/dirty.rb:33:in > `save!' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:246:in > `block in save!' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:295:in > `block in with_transaction_returning_status' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/connection_adapters/abstract/database_statements.rb:192:in > `transaction' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:208:in > `transaction' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:293:in > `with_transaction_returning_status' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:246:in > `save!' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/associations/has_many_association.rb:14:in > `insert_record' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/associations/collection_association.rb:434:in > `block (2 levels) in create_record' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/associations/collection_association.rb:342:in > `add_to_target' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/associations/collection_association.rb:432:in > `block in create_record' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/associations/collection_association.rb:149:in > `block in transaction' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/connection_adapters/abstract/database_statements.rb:192:in > `transaction' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:208:in > `transaction' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/associations/collection_association.rb:148:in > `transaction' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/associations/collection_association.rb:431:in > `create_record' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/associations/collection_association.rb:123:in > `create!' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/associations/collection_proxy.rb:46:in > `create!' > > > /usr/share/foreman/app/services/fact_importer.rb:68:in `block in > add_new_facts' > > > /usr/share/foreman/app/services/fact_importer.rb:67:in `each' > > > /usr/share/foreman/app/services/fact_importer.rb:67:in `add_new_facts' > > > /usr/share/foreman/app/services/fact_importer.rb:36:in `import!' > > > /usr/share/foreman/app/models/host/base.rb:121:in `import_facts' > > > /usr/share/foreman/app/models/host/managed.rb:516:in > `import_host_and_facts' > > > /usr/share/foreman/app/controllers/api/v2/hosts_controller.rb:229:in > `facts' > > > > /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:in > `process_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:in > `block in process_action' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:518:in > `block (5 levels) in > _run__3026391986581779854__process_action__3851232205623071956__callbacks' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in > `block in _conditional_callback_around_12396' > > > /usr/share/foreman/app/controllers/api/v2/base_controller.rb:151:in > `disable_json_root' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in > `_conditional_callback_around_12396' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:495:in > `block (4 levels) in > _run__3026391986581779854__process_action__3851232205623071956__callbacks' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in > `block in _conditional_callback_around_12395' > > > > /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_4179' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in > `_conditional_callback_around_12395' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:483:in > `block (3 levels) in > _run__3026391986581779854__process_action__3851232205623071956__callbacks' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in > `block in _conditional_callback_around_12394' > > > /usr/share/foreman/app/controllers/concerns/application_shared.rb:13:in > `set_timezone' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in > `_conditional_callback_around_12394' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:482:in > `block (2 levels) in > _run__3026391986581779854__process_action__3851232205623071956__callbacks' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in > `block in _conditional_callback_around_12393' > > > /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in > `clear_thread' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in > `_conditional_callback_around_12393' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:437:in > `block in > _run__3026391986581779854__process_action__3851232205623071956__callbacks' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in > `block in _conditional_callback_around_12392' > > > > /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_13' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in > `_conditional_callback_around_12392' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:403:in > `_run__3026391986581779854__process_action__3851232205623071956__callbacks' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in > `__run_callback' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in > `_run_process_action_callbacks' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in > `run_callbacks' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/callbacks.rb:17:in > `process_action' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rescue.rb:29:in > `process_action' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:30:in > `block in process_action' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in > `block in instrument' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications/instrumenter.rb:20:in > `instrument' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in > `instrument' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:29:in > `process_action' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/params_wrapper.rb:207:in > `process_action' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/railties/controller_runtime.rb:18:in > `process_action' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/base.rb:121:in > `process' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/rendering.rb:45:in > `process' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal.rb:203:in > `dispatch' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rack_delegation.rb:14:in > `dispatch' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal.rb:246:in > `block in action' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:73:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:73:in > `dispatch' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:36:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/mapper.rb:42:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:68:in > `block in call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in > `each' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:600:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in > `call' > > > > /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.2.6/lib/apipie/extractor/recorder.rb:97:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in > `call' > > > > /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.2.6/lib/apipie/middleware/checksum_in_headers.rb:27:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/best_standards_support.rb:17:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/etag.rb:23:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/conditionalget.rb:35:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/head.rb:14:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/params_parser.rb:21:in > `call' > > > /usr/share/foreman/lib/middleware/catch_json_parse_errors.rb:9:in `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/flash.rb:242:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:205:in > `context' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:200:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/cookies.rb:339:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/query_cache.rb:64:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/connection_adapters/abstract/connection_pool.rb:473:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:28:in > `block in call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in > `_run__3465221670514608859__call__821409028543683544__callbacks' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in > `__run_callback' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in > `_run_call_callbacks' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in > `run_callbacks' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:27:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/remote_ip.rb:31:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/debug_exceptions.rb:16:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/show_exceptions.rb:56:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:26:in > `call_app' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:16:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/request_id.rb:22:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/methodoverride.rb:21:in > `call' > > > > /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/runtime.rb:17:in > `call' > > > > /opt/rh/ruby193/root/u

Replying again…

puppet facts find <host> gives me the timestamp fact like so:
"timestamp":"Wed Apr 20 21:04:04 +0000 2016"

So, in Puppet it's timestamp (without the leading underscore), and yet in
Foreman it's trying to write it with the leading underscore.

Where would the fact be rewritten with the leading underscore? Doesn't
seem to be in fact_parser.rb. BTW, Puppet version is 3.8.6.

Thanks!

/Mike

··· On Monday, February 8, 2016 at 8:52:01 AM UTC-5, Pulfer Pierre-Alain wrote: > > > >

You were right : Facts yaml files are present in /var/lib/puppet/yaml/facts
on my Foreman server. The problem is when foreman imports the facts.
No custom facts. I didn't found odd facts on yaml files.

Trying to find facts import logs… : Not found until now :frowning:

··· Le jeudi 11 février 2016 10:40:32 UTC+1, Greg Sutcliffe a écrit : > > On 8 February 2016 at 13:44, Pulfer Pierre-Alain > wrote: > > > > Hello all, > > > > Trying to troubleshoot a problem with Foreman 1.10.1 and uploading facts > from host > > > > Upload of facts from host to Foreman is working « only the first time », > when I validate a new host certificate on Foreman web UI. After that, there > is no more facts updates. > > > > Exception : All is working fine for the local server facts (= for the > server hosting foreman). > > > > The error is : ActiveRecord::RecordInvalid: Validation failed: Fact name > has already been taken > > > > production.log when trying to upload facts : > > > > 2016-02-08 14:00:15 [app] [I] Started POST "/api/hosts/facts" for > 10.0.19.50 at 2016-02-08 14:00:15 +0100 > > 2016-02-08 14:00:15 [app] [I] Processing by > Api::V2::HostsController#facts as JSON > > 2016-02-08 14:00:15 [app] [I] Parameters: {"facts"=>"[FILTERED]", > "name"=>"lslpput02.mydomain.com", "certname"=>"lslpput02.mydomain.com", > "apiv"=>"v2", :host=>{"name"=>"lslpput02.mydomain.com", "certname"=>" > lslpput02.mydomain.com"}} > > 2016-02-08 14:00:15 [app] [W] Action failed | > ActiveRecord::RecordInvalid: Validation failed: Fact name has already been > taken > > > > Any idea ? > > > > My ideas are cert problems, or firewall problems (but host reports to > foreman are OK…), or http proxy ( ??...) problems. But i’ve no idea how to > troubleshoot… > > This is not a network issue - the logs above show Foreman receiving the > facts and then aborting due to an issue with the contained data. Do you > have any custom facts or other odd fact data that might cause issues? > > Greg >

OK, a colleague was searching out the "_timestamp" issue, and discovered
it's a "hidden" fact that puppet agent sends to the puppet master.

It's in the 3.x versions of Puppet, but deprecated and removed from Puppet
4.

https://tickets.puppetlabs.com/browse/PDB-337
https://tickets.puppetlabs.com/browse/PUP-3129
https://tickets.puppetlabs.com/browse/PUP-3130

The timestamp is not displayed as part of the Foreman stored facts (either
in the GUI or via hammer fact list --search host={hostname}. However, it
seems that Foreman does use a timestamp in some fashion, and this is where
the conflict comes from, which prevents the foreman report processor from
adding new facts to the host facts.

pwd && grep -r "_timestamp" * | grep -v "log"

/usr/share/foreman
app/models/host_status/status.rb: before_validation :update_timestamp, :if => ->(status) { status.reported_at.blank? }
app/models/host_status/status.rb: update_timestamp
app/models/host_status/status.rb: def update_timestamp
app/models/host_status/configuration_status.rb: def update_timestamp
app/models/fact_value.rb: scope :no_timestamp_facts, lambda {
app/models/fact_value.rb: includes(:fact_name).where("fact_names.name <> ?",:_timestamp)
app/models/fact_value.rb: joins(:fact_name).where("fact_names.name = ?",:_timestamp)
app/models/fact_name.rb: scope :no_timestamp_fact, -> { where("fact_names.name <> ?",:_timestamp) }
app/models/fact_name.rb: scope :timestamp_facts, -> { where(:name => :_timestamp) }
app/models/host/base.rb: time = facts[:_timestamp]
app/controllers/api/v2/fact_values_controller.rb: no_timestamp_facts.
app/controllers/api/v1/fact_values_controller.rb: no_timestamp_facts.
app/controllers/fact_values_controller.rb: base = resource_base.no_timestamp_facts
app/controllers/fact_values_controller.rb: @fact_values = values.no_timestamp_facts.required_fields.paginate :page => params[:page]
app/controllers/facts_controller.rb: render :json => FactName.no_timestamp_fact
app/helpers/trends_helper.rb: next_timestamp = counter.try(:interval_end) || Time.now
app/helpers/trends_helper.rb: data << [next_timestamp.to_i*1000 - 1, counter.count]
app/views/users/_user_fact.html.erb: <%= f.collection_select :fact_name_id, FactName.no_timestamp_fact, :id, :name, {}, :class => "form-control" %>
app/views/trends/_form.html.erb: <%= select_f(f, :trendable_id, FactName.no_timestamp_fact, :id, :name, { :include_blank => true }, :disabled => true) %>
lib/timed_cached_store.rb: delete_if_expired($1) if key =~ /(\w+)_timestamp/
lib/timed_cached_store.rb: "#{name}_timestamp"
lib/tasks/convert.rake: DevelopmentModelClass.record_timestamps = false

and

pwd && grep -r "_timestamp" *

/usr/share/katello-installer
modules/foreman/spec/static_fixtures/fake.host.fqdn.com.yaml: !ruby/sym "_timestamp": 2013-08-02 18:40:14.147766 +01:00

So, anybody have any idea how to handle this?

Thanks!

/Mike

··· On Wednesday, April 20, 2016 at 5:09:37 PM UTC-4, mkb...@solutionsathand.ca wrote: > > Replying again... > > puppet facts find gives me the timestamp fact like so: > "timestamp":"Wed Apr 20 21:04:04 +0000 2016" > > So, in Puppet it's timestamp (without the leading underscore), and yet in > Foreman it's trying to write it with the leading underscore. > > Where would the fact be rewritten with the leading underscore? Doesn't > seem to be in fact_parser.rb. BTW, Puppet version is 3.8.6. > > Thanks! > > /Mike > > On Monday, February 8, 2016 at 8:52:01 AM UTC-5, Pulfer Pierre-Alain wrote: >> >> >> >> >

Hi, I'm also having the same issue but with a Windows client. Katello 2.4
(Puppet 3.8.6). Same behavior, I don't see the facts on the "Hosts" page in
the UI, but I can view this host's facts if I click the "Facts" button from
the host's dedicated page.

Any way to see what fact name specifically the error is referencing?

I don't see any unusual facts, and I haven't added any custom facts.

2016-03-21 21:44:04 [app] [I] Parameters:
{"name"=>"vcenter.domain.local", "certname"=>"vcenter.domain.local",
"facts"=>"[FILTERED]", "apiv"=>"v2",
:host=>{"name"=>"vcenter.domain.local", "certname"=>"vcenter.domain.local"}}
2016-03-21 21:44:04 [app] [W] Action failed
> ActiveRecord::RecordInvalid: Validation failed: Fact name has already
been taken

>
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/validations.rb:56:in
save!&#39; &gt; /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/attribute_methods/dirty.rb:33:insave!'

Thanks,
El-ad

··· On Saturday, February 13, 2016 at 1:01:55 AM UTC+2, Pierre-Alain Pulfer wrote: > > You were right : Facts yaml files are present > in /var/lib/puppet/yaml/facts on my Foreman server. The problem is when > foreman imports the facts. > No custom facts. I didn't found odd facts on yaml files. > > Trying to find facts import logs... : Not found until now :( > > > > > > Le jeudi 11 février 2016 10:40:32 UTC+1, Greg Sutcliffe a écrit : >> >> On 8 February 2016 at 13:44, Pulfer Pierre-Alain < >> Pierre-Al...@lausanne.ch> wrote: >> > >> > Hello all, >> > >> > Trying to troubleshoot a problem with Foreman 1.10.1 and uploading >> facts from host >> > >> > Upload of facts from host to Foreman is working « only the first time >> », when I validate a new host certificate on Foreman web UI. After that, >> there is no more facts updates. >> > >> > Exception : All is working fine for the local server facts (= for the >> server hosting foreman). >> > >> > The error is : ActiveRecord::RecordInvalid: Validation failed: Fact >> name has already been taken >> > >> > production.log when trying to upload facts : >> > >> > 2016-02-08 14:00:15 [app] [I] Started POST "/api/hosts/facts" for >> 10.0.19.50 at 2016-02-08 14:00:15 +0100 >> > 2016-02-08 14:00:15 [app] [I] Processing by >> Api::V2::HostsController#facts as JSON >> > 2016-02-08 14:00:15 [app] [I] Parameters: {"facts"=>"[FILTERED]", >> "name"=>"lslpput02.mydomain.com", "certname"=>"lslpput02.mydomain.com", >> "apiv"=>"v2", :host=>{"name"=>"lslpput02.mydomain.com", "certname"=>" >> lslpput02.mydomain.com"}} >> > 2016-02-08 14:00:15 [app] [W] Action failed | >> ActiveRecord::RecordInvalid: Validation failed: Fact name has already been >> taken >> > >> > Any idea ? >> > >> > My ideas are cert problems, or firewall problems (but host reports to >> foreman are OK…), or http proxy ( ??...) problems. But i’ve no idea how to >> troubleshoot… >> >> This is not a network issue - the logs above show Foreman receiving the >> facts and then aborting due to an issue with the contained data. Do you >> have any custom facts or other odd fact data that might cause issues? >> >> Greg >> >

Issue created in the tracker: Bug #14761: _timestamp fact prevents facts upload through Foreman facts update - Foreman

Cheers!

/Mike

··· On Thursday, April 21, 2016 at 11:07:31 AM UTC-4, mkb...@solutionsathand.ca wrote: > > OK, a colleague was searching out the "_timestamp" issue, and discovered > it's a "hidden" fact that puppet agent sends to the puppet master. > > It's in the 3.x versions of Puppet, but deprecated and removed from Puppet > 4. > > https://tickets.puppetlabs.com/browse/PDB-337 > https://tickets.puppetlabs.com/browse/PUP-3129 > https://tickets.puppetlabs.com/browse/PUP-3130 > > The timestamp is not displayed as part of the Foreman stored facts (either > in the GUI or via hammer fact list --search host={hostname}. However, it > seems that Foreman does use a timestamp in some fashion, and this is where > the conflict comes from, which prevents the foreman report processor from > adding new facts to the host facts. > > # pwd && grep -r "_timestamp" * | grep -v "log" > /usr/share/foreman > app/models/host_status/status.rb: before_validation :update_timestamp, :if => ->(status) { status.reported_at.blank? } > app/models/host_status/status.rb: update_timestamp > app/models/host_status/status.rb: def update_timestamp > app/models/host_status/configuration_status.rb: def update_timestamp > app/models/fact_value.rb: scope :no_timestamp_facts, lambda { > app/models/fact_value.rb: includes(:fact_name).where("fact_names.name <> ?",:_timestamp) > app/models/fact_value.rb: joins(:fact_name).where("fact_names.name = ?",:_timestamp) > app/models/fact_name.rb: scope :no_timestamp_fact, -> { where("fact_names.name <> ?",:_timestamp) } > app/models/fact_name.rb: scope :timestamp_facts, -> { where(:name => :_timestamp) } > app/models/host/base.rb: time = facts[:_timestamp] > app/controllers/api/v2/fact_values_controller.rb: no_timestamp_facts. > app/controllers/api/v1/fact_values_controller.rb: no_timestamp_facts. > app/controllers/fact_values_controller.rb: base = resource_base.no_timestamp_facts > app/controllers/fact_values_controller.rb: @fact_values = values.no_timestamp_facts.required_fields.paginate :page => params[:page] > app/controllers/facts_controller.rb: render :json => FactName.no_timestamp_fact > app/helpers/trends_helper.rb: next_timestamp = counter.try(:interval_end) || Time.now > app/helpers/trends_helper.rb: data < app/views/users/_user_fact.html.erb: <%= f.collection_select :fact_name_id, FactName.no_timestamp_fact, :id, :name, {}, :class => "form-control" %> > app/views/trends/_form.html.erb: <%= select_f(f, :trendable_id, FactName.no_timestamp_fact, :id, :name, { :include_blank => true }, :disabled => true) %> > lib/timed_cached_store.rb: delete_if_expired($1) if key =~ /(\w+)_timestamp/ > lib/timed_cached_store.rb: "#{name}_timestamp" > lib/tasks/convert.rake: DevelopmentModelClass.record_timestamps = false > > and > > # pwd && grep -r "_timestamp" * > /usr/share/katello-installer > modules/foreman/spec/static_fixtures/fake.host.fqdn.com.yaml: !ruby/sym "_timestamp": 2013-08-02 18:40:14.147766 +01:00 > > > So, anybody have any idea how to handle this? > > Thanks! > > /Mike > > > On Wednesday, April 20, 2016 at 5:09:37 PM UTC-4, > mkb...@solutionsathand.ca wrote: >> >> Replying again... >> >> puppet facts find gives me the timestamp fact like so: >> "timestamp":"Wed Apr 20 21:04:04 +0000 2016" >> >> So, in Puppet it's timestamp (without the leading underscore), and yet in >> Foreman it's trying to write it with the leading underscore. >> >> Where would the fact be rewritten with the leading underscore? Doesn't >> seem to be in fact_parser.rb. BTW, Puppet version is 3.8.6. >> >> Thanks! >> >> /Mike >> >> On Monday, February 8, 2016 at 8:52:01 AM UTC-5, Pulfer Pierre-Alain >> wrote: >>> >>> >>> >>> >>

>
> Got the same problem. Even after Update to 1.11
>>>
>>

Are there any solutions to solve this meanwhile?

– Tom

2016-04-12 08:55:43 [app] [I] Parameters: {"facts"=>"[FILTERED]",
"name"=>"vm-tomfore-001.to3.loc", "certname"=>"vm-tomfore-001.to3.loc",
"apiv"=>"v2", :host=>{"name"=>"vm-tomfore-001.to3.loc",
"certname"=>"vm-tomfore-001.to3.loc"}}
2016-04-12 08:55:43 [app] [W] Action failed
> ActiveRecord::RecordInvalid: Validation failed: Fact name has already
been taken
>
/opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/validations.rb:57:in
save!&#39; &gt; /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/attribute_methods/dirty.rb:29:insave!'
>
/opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/transactions.rb:273:in
block in save!&#39; &gt; /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/transactions.rb:329:inblock in with_transaction_returning_status'
>
/opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/abstract/database_statements.rb:199:in
transaction&#39; &gt; /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/transactions.rb:208:intransaction'
>
/opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/transactions.rb:326:in
with_transaction_returning_status&#39; &gt; /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/transactions.rb:273:insave!'
>
/opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/associations/has_many_association.rb:38:in
insert_record&#39; &gt; /opt/theforeman/tfm/root/usr/share/gems/gems/protected_attributes-1.1.3/lib/active_record/mass_assignment_security/associations.rb:50:inblock (2 levels) in create_record'
>
/opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/associations/collection_association.rb:389:in
add_to_target&#39; &gt; /opt/theforeman/tfm/root/usr/share/gems/gems/protected_attributes-1.1.3/lib/active_record/mass_assignment_security/associations.rb:48:inblock in create_record'
>
/opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/associations/collection_association.rb:168:in
block in transaction&#39; &gt; /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/abstract/database_statements.rb:201:inblock in transaction'
>
/opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/abstract/database_statements.rb:209:in
within_new_transaction&#39; &gt; /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/abstract/database_statements.rb:201:intransaction'
>
/opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/transactions.rb:208:in
transaction&#39; &gt; /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/associations/collection_association.rb:167:intransaction'
>
/opt/theforeman/tfm/root/usr/share/gems/gems/protected_attributes-1.1.3/lib/active_record/mass_assignment_security/associations.rb:47:in
create_record&#39; &gt; /opt/theforeman/tfm/root/usr/share/gems/gems/protected_attributes-1.1.3/lib/active_record/mass_assignment_security/associations.rb:36:increate!'
>
/opt/theforeman/tfm/root/usr/share/gems/gems/protected_attributes-1.1.3/lib/active_record/mass_assignment_security/associations.rb:73:in
`create!'