[PDB-865] Puppet DB Migrations Do not Handle Bad Data Created: 2014/09/10  Updated: 2016/04/27  Resolved: 2014/09/16

Status: Closed
Project: PuppetDB
Component/s: None
Affects Version/s: PDB 2.2.0
Fix Version/s: PDB 2.2.1

Type: Bug Priority: Blocker
Reporter: Tom Vachon Assignee: Wyatt Alt
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Template:
Story Points: 2
Sprint: PuppetDB 2014-09-24

 Description   

When running an upgrade from 1.6 to 2.2, I would get a failed assertion on the v25 upgrade.

Diving into the debug logs, it showed a host which had a certnbame but no factset, causing it to try and map in a null value and insert into the database.

The host in question was marked as decommissioned. Removing the host from certnames fixed the issue.

2014-09-10 15:56:17,166 DEBUG [c.j.b.PreparedStatementHandle] INSERT INTO facts (fact_value_id,factset_id) VALUES (49,1)
2014-09-10 15:56:17,167 DEBUG [c.j.b.PreparedStatementHandle] INSERT INTO facts (fact_value_id,factset_id) VALUES (84,1)
2014-09-10 15:56:17,168 DEBUG [c.j.b.PreparedStatementHandle] SELECT * FROM certname_facts WHERE certname = 'ip-10-48-11-194.hnd.example.com'
2014-09-10 15:56:17,168 DEBUG [c.j.b.PreparedStatementHandle] SELECT name FROM environments WHERE id = NULL
2014-09-10 15:56:17,169 DEBUG [c.j.b.PreparedStatementHandle] INSERT INTO factsets (certname,timestamp,environment_id,producer_timestamp) VALUES ('ip-10-48-11-194.hnd.example.com',2014-05-15 15:15:18.43,NULL,NULL)
2014-09-10 15:56:17,203 ERROR [p.t.logging] Uncaught exception
java.lang.AssertionError: Assert failed: (seq coll)
	at com.puppetlabs.jdbc$in_clause_multi.invoke(jdbc.clj:329) ~[na:na]
	at com.puppetlabs.puppetdb.scf.storage$eval9462$fact_path_current_ids__9463$fn__9464.invoke(storage.clj:799) ~[na:na]
	at com.puppetlabs.puppetdb.scf.storage$eval9462$fact_path_current_ids__9463.invoke(storage.clj:787) ~[na:na]
	at com.puppetlabs.puppetdb.scf.storage$eval9512$fact_paths_to_ids__9513$fn__9514.invoke(storage.clj:824) ~[na:na]
	at com.puppetlabs.puppetdb.scf.storage$eval9512$fact_paths_to_ids__9513.invoke(storage.clj:821) ~[na:na]
	at com.puppetlabs.puppetdb.scf.storage$eval9607$new_fact_value_ids_STAR___9608$fn__9609.invoke(storage.clj:902) ~[na:na]
	at com.puppetlabs.puppetdb.scf.storage$eval9607$new_fact_value_ids_STAR___9608.invoke(storage.clj:897) ~[na:na]
	at com.puppetlabs.puppetdb.scf.storage$eval9631$new_fact_value_ids__9632$fn__9633.invoke(storage.clj:926) ~[na:na]
	at com.puppetlabs.puppetdb.scf.storage$eval9631$new_fact_value_ids__9632.invoke(storage.clj:919) ~[na:na]
	at com.puppetlabs.puppetdb.scf.storage$eval9731$add_facts_BANG___9732$fn__9736.invoke(storage.clj:980) ~[na:na]
	at com.puppetlabs.puppetdb.scf.storage$eval9731$add_facts_BANG___9732.invoke(storage.clj:971) ~[na:na]
	at com.puppetlabs.puppetdb.scf.migrate$migrate_to_structured_facts.invoke(migrate.clj:726) ~[na:na]
	at com.puppetlabs.puppetdb.scf.migrate$structured_facts.invoke(migrate.clj:840) ~[na:na]
	at com.puppetlabs.puppetdb.scf.migrate$migrate_BANG_$fn__18759$fn__18772.invoke(migrate.clj:924) ~[na:na]
	at com.puppetlabs.puppetdb.scf.migrate$migrate_BANG_$fn__18759.invoke(migrate.clj:923) ~[na:na]
	at clojure.java.jdbc.internal$transaction_STAR_.invoke(internal.clj:204) ~[na:na]
	at com.puppetlabs.puppetdb.scf.migrate$migrate_BANG_.invoke(migrate.clj:920) ~[na:na]
	at com.puppetlabs.puppetdb.cli.services$start_puppetdb$fn__18893.invoke(services.clj:291) ~[na:na]
	at clojure.java.jdbc.internal$with_connection_STAR_.invoke(internal.clj:186) ~[na:na]
	at com.puppetlabs.puppetdb.cli.services$start_puppetdb.invoke(services.clj:289) ~[na:na]
	at com.puppetlabs.puppetdb.cli.services$reify__18941$f_positional__18950$fnk18983_positional__18984$fn__18985.invoke(services.clj:354) ~[na:na]
	at com.puppetlabs.puppetdb.cli.services$reify__18941$fn$reify__19055.start(services.clj:354) ~[na:na]
	at puppetlabs.trapperkeeper.services$eval16061$fn__16075$G__16051__16078.invoke(services.clj:12) ~[na:na]
	at puppetlabs.trapperkeeper.services$eval16061$fn__16075$G__16050__16082.invoke(services.clj:12) ~[na:na]
	at puppetlabs.trapperkeeper.internal$run_lifecycle_fn_BANG_.invoke(internal.clj:143) ~[na:na]
	at puppetlabs.trapperkeeper.internal$run_lifecycle_fns.invoke(internal.clj:170) ~[na:na]
	at puppetlabs.trapperkeeper.internal$build_app_STAR_$reify__17140.start(internal.clj:385) ~[na:na]
	at puppetlabs.trapperkeeper.internal$boot_services_STAR_.invoke(internal.clj:401) ~[na:na]
	at puppetlabs.trapperkeeper.core$boot_with_cli_data.invoke(core.clj:114) ~[na:na]
	at puppetlabs.trapperkeeper.core$run.invoke(core.clj:145) ~[na:na]
	at puppetlabs.trapperkeeper.core$main.doInvoke(core.clj:160) ~[na:na]
	at clojure.lang.RestFn.applyTo(RestFn.java:137) [puppetdb.jar:na]
	at clojure.core$apply.invoke(core.clj:624) [puppetdb.jar:na]
	at com.puppetlabs.puppetdb.cli.services$_main.doInvoke(services.clj:370) ~[na:na]
	at clojure.lang.RestFn.invoke(RestFn.java:421) [puppetdb.jar:na]
	at clojure.lang.Var.invoke(Var.java:383) [puppetdb.jar:na]
	at clojure.lang.AFn.applyToHelper(AFn.java:156) [puppetdb.jar:na]
	at clojure.lang.Var.applyTo(Var.java:700) [puppetdb.jar:na]
	at clojure.core$apply.invoke(core.clj:624) [puppetdb.jar:na]
	at com.puppetlabs.puppetdb.core$run_command.invoke(core.clj:87) ~[na:na]
	at com.puppetlabs.puppetdb.core$_main.doInvoke(core.clj:95) [na:na]
	at clojure.lang.RestFn.invoke(RestFn.java:436) [puppetdb.jar:na]
	at clojure.lang.Var.invoke(Var.java:388) [puppetdb.jar:na]
	at clojure.lang.AFn.applyToHelper(AFn.java:160) [puppetdb.jar:na]
	at clojure.lang.Var.applyTo(Var.java:700) [puppetdb.jar:na]
	at clojure.core$apply.invoke(core.clj:624) [puppetdb.jar:na]
	at clojure.main$main_opt.invoke(main.clj:315) [puppetdb.jar:na]
	at clojure.main$main.doInvoke(main.clj:420) [puppetdb.jar:na]
	at clojure.lang.RestFn.invoke(RestFn.java:482) [puppetdb.jar:na]
	at clojure.lang.Var.invoke(Var.java:401) [puppetdb.jar:na]
	at clojure.lang.AFn.applyToHelper(AFn.java:171) [puppetdb.jar:na]
	at clojure.lang.Var.applyTo(Var.java:700) [puppetdb.jar:na]
	at clojure.main.main(main.java:37) [puppetdb.jar:na]

The database shows its state here:

puppetdb-# select * from certname_facts where certname  = 'ip-10-48-11-194.hnd.example.com'
puppetdb-# select * from facts where certnames = 'ip-10-48-11-194.hnd.example.com'
puppetdb=# select * from certnames where name = 'ip-10-48-11-194.hnd.example.com';
               name               |        deactivated
----------------------------------+----------------------------
 ip-10-48-11-194.hnd.example.com | 2014-05-15 15:37:16.463+00
(1 row)


Generated at Mon Sep 23 12:33:32 PDT 2019 using JIRA 7.7.1#77002-sha1:e75ca93d5574d9409c0630b81c894d9065296414.