Facts upload failed: Description has already been taken

Problem:

Newer puppet clients cannot report facts properly: in the foreman dashboard they are missing operating system, environment, location et al.

Clients created only a few days ago work fine.

In the meanwhile I have upgraded foreman from 1.21 to 1.24. Unfortunately I have also changed the golden image from which clients are created.

During execution of puppet agent -t in foreman log show up lines pasted below.

I am not sure what description and title are: is it something I should add to the puppet’s node’s description?

Foreman and Proxy versions:
foreman-1.24.2

Distribution and version:
Debian GNU/Linux 9 (stretch)

Other relevant data:

2020-02-26 12:44:34,140 WARN  [qtp1699378064-878257] [c.p.p.ShellUtils] Executed an external process which logged to STDERR: During the fact upload the server responded with: 500 Internal Server Error. Error is ignored and the execution continues.
{
  "error": {"message":"Validation failed: Description has already been taken, Title has already been taken"}
}

Multiple users are reporting this to us, we are tracking this problem under:

@ekohl are you aware of any changes in puppet clients in this regard? Why this appears to be only on Debians? My suspicion:

@Marek_Hulan any insights?

I believe that patch removed parsing of Debian fact, puppet probably does not return major.minor as numbers for Debians?!? We used to convert names to major versions. Not sure, just guessing.

We should really be correct and say facter. I’ve posted Bug #29110: Uploading facts from Debian 10 (Buster) nodes returns error message from Foreman - Foreman which confirms that there is no minor anymore in the (legacy) fact we use.

Thank you so much: I’m now a lot reassured. And now I understand a lot better what is going on.

I don’t do Debian provisioning, someone who can test this can chip in? It’s probably minor change but it needs to be tested.

It doesn’t look a issue in major/minor version parsing. I added a few debug line and it prints:

2020-03-02T09:21:54 [I|app|78119549] orel: 10.3
2020-03-02T09:21:54 [I|app|78119549] major: 10
2020-03-02T09:21:54 [I|app|78119549] minor: 3
2020-03-02T09:21:54 [I|app|78119549] os_name: Debian
2020-03-02T09:21:54 [W|app|78119549] Action failed
2020-03-02T09:21:54 [I|app|78119549]   Rendering api/v2/errors/standard_error.json.rabl within api/v2/layouts/error_layout
2020-03-02T09:21:54 [I|app|78119549]   Rendered api/v2/errors/standard_error.json.rabl within api/v2/layouts/error_layout (2.5ms)
2020-03-02T09:21:54 [I|app|78119549] Completed 500 Internal Server Error in 1888ms (Views: 7.0ms | ActiveRecord: 173.0ms)

so I would blame the following line:

Operatingsystem.find_or_initialize_by(args)

but to confirm it I would need to access the rails console.

A naive doesn’t work:

sudo -u foreman RAILS_ENV=production ./bin/rails c
/usr/lib/ruby/2.3.0/rubygems/core_ext/kernel_require.rb:55:in `require': cannot load such file -- active_support/dependencies (LoadError)
	from /usr/lib/ruby/2.3.0/rubygems/core_ext/kernel_require.rb:55:in `require'
	from /usr/share/foreman/config/boot.rb:7:in `<top (required)>'
	from ./bin/rails:8:in `require_relative'
	from ./bin/rails:8:in `<main>'

We have a helper for that: foreman-rake console.

Can you show me what you currently have in the database:

> Operatingsystem.where(type: "Debian").pluck(:title, :description, :name, :minor, :major, :release_name)
=> [["Debian 5", "Debian 5", "Debian", "", "5", "unknown"]]

And then issue debug statements and find what’s actually being saved, for example add Rails.logger.info os.incpect just above os.save statement. From there we can figure out why it fails.

Obviously, it incorrectly ignores an existing entry and tries to create a new one which fails to validate.

=> [["Debian 10", "Debian 10", "Debian", "", "10", "buster"], ["Debian 10.2", nil, "Debian", "2", "10", "unknown"], ["Debian 8.11", "Debian 8.11", "Debian", "11", "8", "jessie"], ["Debian 9.11", "Debian 9.11", "Debian", "11", "9", "stretch"], ["Debian 9.12", "Debian 9.12", "Debian", "12", "9", "stretch"]]

Before save it logs out:

2020-03-02T10:19:31 [I|app|62fed8f9] #<Operatingsystem id: nil, major: "10", name: "Debian", minor: "3", nameindicator: nil, created_at: nil, updated_at: nil, release_name: "buster", type: nil, description: "Debian 10", password_hash: "SHA256", title: nil>
2020-03-02T10:19:32 [W|app|62fed8f9] Action failed

thank you,

Can you also pastebin relevant facter output of that host? I think @ekohl 's suspicion in the redmine issue is correct. We still parse legacy facts which do not carry enough information anymore (minor version).

$ facter os
{
  architecture => "amd64",
  distro => {
    codename => "buster",
    description => "Debian GNU/Linux 10 (buster)",
    id => "Debian",
    release => {
      full => "10.3",
      major => "10",
      minor => "3"
    }
  },
  family => "Debian",
  hardware => "x86_64",
  name => "Debian",
  release => {
    full => "10.3",
    major => "10",
    minor => "3"
  },
  selinux => {
    enabled => false
  }
}

is it enought?

Try this:

diff --git a/app/services/puppet_fact_parser.rb b/app/services/puppet_fact_parser.rb
index 92e0e29a8..5d6059cd3 100644
--- a/app/services/puppet_fact_parser.rb
+++ b/app/services/puppet_fact_parser.rb
@@ -212,9 +212,9 @@ class PuppetFactParser < FactParser
       '1.0'
     when /Debian/i
       return "99" if facts[:lsbdistcodename] =~ /sid/
-      facts[:lsbdistrelease] || facts[:operatingsystemrelease]
+      facts.dig(:os, :release, :full) || facts[:lsbdistrelease] || facts[:operatingsystemrelease]
     else
-      facts[:lsbdistrelease] || facts[:operatingsystemrelease]
+      facts.dig(:os, :release, :full) || facts[:lsbdistrelease] || facts[:operatingsystemrelease]
     end
   end
 end

unfortunately not.

2020-03-02T10:44:49 [I|app|d9110664] facts dig: 10.3
2020-03-02T10:44:49 [I|app|d9110664] lsbdistrelease: 10.3
2020-03-02T10:44:49 [I|app|d9110664] operatingsystemrelease: 10.3
2020-03-02T10:44:49 [I|app|d9110664] orel: 10.3
2020-03-02T10:44:49 [I|app|d9110664] major: 10
2020-03-02T10:44:49 [I|app|d9110664] minor: 3
2020-03-02T10:44:49 [I|app|d9110664] os_name: Debian
2020-03-02T10:44:49 [I|app|d9110664] #<Operatingsystem id: nil, major: "10", name: "Debian", minor: "3", nameindicator: nil, created_at: nil, updated_at: nil, release_name: "buster", type: nil, description: "Debian 10", password_hash: "SHA256", title: nil>

the three conditions: facts.dig(:os, :release, :full) || facts[:lsbdistrelease] || facts[:operatingsystemrelease] all report: “10.3”.

I wonder if Operatingsystem.find_or_initialize_by(args) has some odd behavior for the empty string minor version.

Nope.

=> #<Debian:0x00007fffd9d3da48
 id: 10,
 major: "5",
 name: "Debian",
 minor: "",
 nameindicator: nil,
 created_at: Wed, 30 Aug 2017 09:27:34 UTC +00:00,
 updated_at: Wed, 30 Aug 2017 09:27:34 UTC +00:00,
 release_name: "unknown",
 type: "Debian",
 description: "Debian 5",
 password_hash: "SHA256",
 title: "Debian 5">
[3] pry(main)> Operatingsystem.find_or_initialize_by(name: "Debian", major: "5", minor: "")
=> #<Debian:0x00007fffd9df6480
 id: 10,
 major: "5",
 name: "Debian",
 minor: "",
 nameindicator: nil,
 created_at: Wed, 30 Aug 2017 09:27:34 UTC +00:00,
 updated_at: Wed, 30 Aug 2017 09:27:34 UTC +00:00,
 release_name: "unknown",
 type: "Debian",
 description: "Debian 5",
 password_hash: "SHA256",
 title: "Debian 5">

Can you get me full, unmodified output of facter --json? Feel free to replace sensitive things like hostnames, ssh keys etc, just keep everything so I can add this to our test suite. I will try to debug locally.

here you are:

facter pastebin

thank you

Try this:

I still have errors (some more debug):

2020-03-03T11:53:11 [I|app|d95dbab0] Import facts for 'homesrvt.example.org' completed. Added: 0, Updated: 0, Deleted 0 facts
2020-03-03T11:53:11 [I|app|d95dbab0] args: {:name=>"Debian", :major=>"10", :minor=>"1"}
2020-03-03T11:53:11 [I|app|d95dbab0] os: #<Operatingsystem id: nil, major: "10", name: "Debian", minor: "1", nameindicator: nil, created_at: nil, updated_at: nil, release_name: nil, type: nil, description: nil, password_hash: "SHA256", title: nil>
2020-03-03T11:53:11 [I|app|d95dbab0] os_name: Debian
2020-03-03T11:53:11 [I|app|d95dbab0] os new record?: true
2020-03-03T11:53:11 [I|app|d95dbab0] os errors: {:description=>["has already been taken"], :title=>["has already been taken"]}
2020-03-03T11:53:11 [W|app|d95dbab0] Action failed

for sure I need to clean db from OperatingSystem objects with missing attributes (ok, it’s fine).

But still it looks Operatingsystem.find_or_initialize_by when args is: {:name=>"Debian", :major=>"10", :minor=>"1"} does not populate :title, :description and :release_name. The lack of any of these marks os as invalid.