Plugins » Foreman Remote Execution

2021-04-08T14:28:46 [I|aud|1864d53d] JobInvocation (80) create event on job_category Commands
2021-04-08T14:28:46 [I|aud|1864d53d] JobInvocation (80) create event on description Run ls -l
2021-04-08T14:28:46 [I|aud|1864d53d] JobInvocation (80) create event on concurrency_level 
2021-04-08T14:28:46 [I|aud|1864d53d] JobInvocation (80) create event on time_span 
2021-04-08T14:28:46 [I|aud|1864d53d] JobInvocation (80) create event on execution_timeout_interval 
2021-04-08T14:28:46 [I|aud|1864d53d] JobInvocation (80) create event on password [redacted]
2021-04-08T14:28:46 [I|aud|1864d53d] JobInvocation (80) create event on key_passphrase 
2021-04-08T14:28:46 [I|aud|1864d53d] JobInvocation (80) create event on remote_execution_feature_id 
2021-04-08T14:28:46 [I|aud|1864d53d] JobInvocation (80) create event on sudo_password 
2021-04-08T14:28:46 [D|app|1864d53d]   TemplateInput Load (0.8ms)  SELECT "template_inputs".* FROM "template_inputs" WHERE "template_inputs"."template_id" = $1 AND "template_inputs"."required" = $2  [["template_id", 157], ["required", true]]
2021-04-08T14:28:46 [D|app|1864d53d]   TemplateInvocation Create (1.9ms)  INSERT INTO "template_invocations" ("template_id", "job_invocation_id", "effective_user") VALUES ($1, $2, $3) RETURNING "id"  [["template_id", 157], ["job_invocation_id", 80], ["effective_user", "root"]]
2021-04-08T14:28:46 [D|app|1864d53d]   TemplateInvocationInputValue Create (2.0ms)  INSERT INTO "template_invocation_input_values" ("template_invocation_id", "template_input_id", "value") VALUES ($1, $2, $3) RETURNING "id"  [["template_invocation_id", 117], ["template_input_id", 47], ["value", "ls -l"]]
2021-04-08T14:28:46 [D|app|1864d53d]    (0.9ms)  SELECT COUNT(*) FROM "permissions" WHERE "permissions"."resource_type" = $1 AND (permissions.name LIKE 'create_%')  [["resource_type", "TemplateInvocation"]]
2021-04-08T14:28:46 [D|app|1864d53d]   Permission Load (0.9ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."resource_type" = $1 AND (permissions.name LIKE 'create_%') ORDER BY "permissions"."id" ASC LIMIT $2  [["resource_type", "TemplateInvocation"], ["LIMIT", 1]]
2021-04-08T14:28:46 [D|app|1864d53d]   Filter Load (5.5ms)  SELECT DISTINCT "filters".* FROM "filters" INNER JOIN "roles" ON "filters"."role_id" = "roles"."id" INNER JOIN "cached_user_roles" ON "roles"."id" = "cached_user_roles"."role_id" INNER JOIN "filterings" ON "filterings"."filter_id" = "filters"."id" INNER JOIN "permissions" ON "permissions"."id" = "filterings"."permission_id" LEFT JOIN taxable_taxonomies ON (filters.id = taxable_taxonomies.taxable_id AND taxable_type = 'Filter') LEFT JOIN taxonomies ON (taxonomies.id = taxable_taxonomies.taxonomy_id) WHERE "cached_user_roles"."user_id" = $1 AND (permissions.resource_type = 'TemplateInvocation') AND (permissions.name = 'create_template_invocations') AND (taxable_taxonomies.id IS NULL OR (taxonomies.type = 'Organization') OR (taxonomies.type = 'Location'))  [["user_id", 5]]
2021-04-08T14:28:46 [D|app|1864d53d]   TemplateInvocation Exists? (0.7ms)  SELECT 1 AS one FROM "template_invocations" WHERE "template_invocations"."id" = $1 LIMIT $2  [["id", 117], ["LIMIT", 1]]
2021-04-08T14:28:46 [D|app|1864d53d]    (0.6ms)  SELECT COUNT(*) FROM "permissions" WHERE "permissions"."resource_type" = $1 AND (permissions.name LIKE 'create_%')  [["resource_type", "JobInvocation"]]
2021-04-08T14:28:46 [D|app|1864d53d]   Permission Load (0.6ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."resource_type" = $1 AND (permissions.name LIKE 'create_%') ORDER BY "permissions"."id" ASC LIMIT $2  [["resource_type", "JobInvocation"], ["LIMIT", 1]]
2021-04-08T14:28:46 [D|app|1864d53d]   Filter Load (3.4ms)  SELECT DISTINCT "filters".* FROM "filters" INNER JOIN "roles" ON "filters"."role_id" = "roles"."id" INNER JOIN "cached_user_roles" ON "roles"."id" = "cached_user_roles"."role_id" INNER JOIN "filterings" ON "filterings"."filter_id" = "filters"."id" INNER JOIN "permissions" ON "permissions"."id" = "filterings"."permission_id" LEFT JOIN taxable_taxonomies ON (filters.id = taxable_taxonomies.taxable_id AND taxable_type = 'Filter') LEFT JOIN taxonomies ON (taxonomies.id = taxable_taxonomies.taxonomy_id) WHERE "cached_user_roles"."user_id" = $1 AND (permissions.resource_type = 'JobInvocation') AND (permissions.name = 'create_job_invocations') AND (taxable_taxonomies.id IS NULL OR (taxonomies.type = 'Organization') OR (taxonomies.type = 'Location'))  [["user_id", 5]]
2021-04-08T14:28:46 [D|app|1864d53d]    (1.0ms)  SELECT "taxonomies"."id" FROM "taxonomies" WHERE (("taxonomies"."ancestry" LIKE '1/%' OR "taxonomies"."ancestry" = '1') OR "taxonomies"."id" = 1) ORDER BY "taxonomies"."title" ASC
2021-04-08T14:28:46 [D|app|1864d53d]   Location Load (0.5ms)  SELECT "taxonomies".* FROM "taxonomies" WHERE "taxonomies"."type" = $1 AND "taxonomies"."id" IN ($2, $3) ORDER BY "taxonomies"."title" ASC  [["type", "Location"], ["id", 2], ["id", 3]]
2021-04-08T14:28:46 [D|app|1864d53d]    (0.5ms)  SELECT "taxonomies"."id" FROM "taxonomies" WHERE (("taxonomies"."ancestry" LIKE '3/%' OR "taxonomies"."ancestry" = '3') OR "taxonomies"."id" = 3) ORDER BY "taxonomies"."title" ASC
2021-04-08T14:28:46 [D|app|1864d53d]    (0.4ms)  SELECT "taxonomies"."id" FROM "taxonomies" WHERE (("taxonomies"."ancestry" LIKE '2/%' OR "taxonomies"."ancestry" = '2') OR "taxonomies"."id" = 2) ORDER BY "taxonomies"."title" ASC
2021-04-08T14:28:46 [D|app|1864d53d]   JobInvocation Exists? (1.6ms)  SELECT 1 AS one FROM "job_invocations" LEFT OUTER JOIN "template_invocations" ON "template_invocations"."job_invocation_id" = "job_invocations"."id" AND (host_id IS NOT NULL) LEFT OUTER JOIN "hosts" ON "hosts"."organization_id" = $1 AND "hosts"."location_id" IN ($2, $3) AND "hosts"."id" = "template_invocations"."host_id" AND "hosts"."type" = $4 WHERE (("job_invocations"."id" IN (SELECT "job_invocations"."id" FROM         "job_invocations" 
        INNER JOIN "template_invocations" 
        ON "job_invocations"."id" = "template_invocations"."job_invocation_id"  
        INNER JOIN "hosts" 
        ON "template_invocations"."host_id" = "hosts"."id" 
 WHERE "hosts"."name" = 'the.host' ))) AND "job_invocations"."id" = $5 LIMIT $6  [["organization_id", 1], ["location_id", 3], ["location_id", 2], ["type", "Host::Managed"], ["id", 80], ["LIMIT", 1]]
2021-04-08T14:28:46 [D|app|1864d53d]   JobInvocation Create (1.4ms)  INSERT INTO "job_invocations" DEFAULT VALUES RETURNING "id" 
2021-04-08T14:28:46 [D|app|1864d53d]    (0.2ms)  ROLLBACK
2021-04-08T14:28:46 [W|app|1864d53d] Action failed
2021-04-08T14:28:46 [D|app|1864d53d] Backtrace for 'Action failed' error (ActiveRecord::NotNullViolation): PG::NotNullViolation: ERROR:  null value in column "targeting_id" violates not-null constraint
DETAIL:  Failing row contains (81, null, null, null, null, null, null, null, null, null, null, null, null, null).

In case there is no filter.

2021-04-09T15:25:27 [D|app|26bb369d]   JobInvocation Exists? (0.4ms)  SELECT 1 AS one FROM "job_invocations" WHERE "job_invocations"."id" = $1 LIMIT $2  [["id", 113], ["LIMIT", 1]]
2021-04-09T15:25:27 [E|app|26bb369d] YYYYYYYYYYYYYYYYYYYYYYYY 28 subject: Run ls -l permission: create_job_invocations erg: SELECT "job_invocations".* FROM "job_invocations" WHERE "job_invocations"."id" = 113 ORDER BY job_invocations.id DESC -- #<ActiveRecord::Relation [#<JobInvocation id: 113, targeting_id: 86, job_category: "Commands", task_id: nil, task_group_id: 88, triggering_id: 85, description: "Run ls -l", concurrency_level: nil, time_span: nil, execution_timeout_interval: nil, password: nil, key_passphrase: nil, remote_execution_feature_id: nil, sudo_password: nil>]> any: true
2021-04-09T15:25:27 [D|app|26bb369d]   CACHE JobInvocation Exists? (0.0ms)  SELECT 1 AS one FROM "job_invocations" WHERE "job_invocations"."id" = $1 LIMIT $2  [["id", 113], ["LIMIT", 1]]

In case there is a host filter for create_job_invocation

2021-04-09T15:18:54 [D|app|cda79c33]   JobInvocation Exists? (1.7ms)  SELECT 1 AS one FROM "job_invocations" LEFT OUTER JOIN "template_invocations" ON "template_invocations"."job_invocation_id" = "job_invocations"."id" AND (host_id IS NOT NULL) LEFT OUTER JOIN "hosts" ON "hosts"."organization_id" = $1 AND "hosts"."location_id" IN ($2, $3) AND "hosts"."id" = "template_invocations"."host_id" AND "hosts"."type" = $4 WHERE (("job_invocations"."id" IN (SELECT "job_invocations"."id" FROM         "job_invocations" 
        INNER JOIN "template_invocations" 
        ON "job_invocations"."id" = "template_invocations"."job_invocation_id"  
        INNER JOIN "hosts" 
        ON "template_invocations"."host_id" = "hosts"."id" 
 WHERE "hosts"."name" = 'AWESOME.HOST.NAME' ))) AND "job_invocations"."id" = $5 LIMIT $6  [["organization_id", 1], ["location_id", 3], ["location_id", 2], ["type", "Host::Managed"], ["id", 111], ["LIMIT", 1]]

2021-04-09T15:18:54 [E|app|cda79c33] YYYYYYYYYYYYYYYYYYYYYYYY 28 subject: Run ls -l permission: create_job_invocations erg: SELECT "job_invocations"."id" AS t0_r0, "job_invocations"."targeting_id" AS t0_r1, "job_invocations"."job_category" AS t0_r2, "job_invocations"."task_id" AS t0_r3, "job_invocations"."task_group_id" AS t0_r4, "job_invocations"."triggering_id" AS t0_r5, "job_invocations"."description" AS t0_r6, "job_invocations"."concurrency_level" AS t0_r7, "job_invocations"."time_span" AS t0_r8, "job_invocations"."execution_timeout_interval" AS t0_r9, "job_invocations"."password" AS t0_r10, "job_invocations"."key_passphrase" AS t0_r11, "job_invocations"."remote_execution_feature_id" AS t0_r12, "job_invocations"."sudo_password" AS t0_r13, "hosts"."id" AS t1_r0, "hosts"."name" AS t1_r1, "hosts"."last_compile" AS t1_r2, "hosts"."last_report" AS t1_r3, "hosts"."updated_at" AS t1_r4, "hosts"."created_at" AS t1_r5, "hosts"."root_pass" AS t1_r6, "hosts"."architecture_id" AS t1_r7, "hosts"."operatingsystem_id" AS t1_r8, "hosts"."environment_id" AS t1_r9, "hosts"."ptable_id" AS t1_r10, "hosts"."medium_id" AS t1_r11, "hosts"."build" AS t1_r12, "hosts"."comment" AS t1_r13, "hosts"."disk" AS t1_r14, "hosts"."installed_at" AS t1_r15, "hosts"."model_id" AS t1_r16, "hosts"."hostgroup_id" AS t1_r17, "hosts"."owner_id" AS t1_r18, "hosts"."owner_type" AS t1_r19, "hosts"."enabled" AS t1_r20, "hosts"."puppet_ca_proxy_id" AS t1_r21, "hosts"."managed" AS t1_r22, "hosts"."use_image" AS t1_r23, "hosts"."image_file" AS t1_r24, "hosts"."uuid" AS t1_r25, "hosts"."compute_resource_id" AS t1_r26, "hosts"."puppet_proxy_id" AS t1_r27, "hosts"."certname" AS t1_r28, "hosts"."image_id" AS t1_r29, "hosts"."organization_id" AS t1_r30, "hosts"."location_id" AS t1_r31, "hosts"."type" AS t1_r32, "hosts"."otp" AS t1_r33, "hosts"."realm_id" AS t1_r34, "hosts"."compute_profile_id" AS t1_r35, "hosts"."provision_method" AS t1_r36, "hosts"."salt_proxy_id" AS t1_r37, "hosts"."grub_pass" AS t1_r38, "hosts"."salt_environment_id" AS t1_r39, "hosts"."discovery_rule_id" AS t1_r40, "hosts"."global_status" AS t1_r41, "hosts"."lookup_value_matcher" AS t1_r42, "hosts"."openscap_proxy_id" AS t1_r43, "hosts"."pxe_loader" AS t1_r44, "hosts"."initiated_at" AS t1_r45, "hosts"."build_errors" AS t1_r46 FROM "job_invocations" LEFT OUTER JOIN "template_invocations" ON "template_invocations"."job_invocation_id" = "job_invocations"."id" AND (host_id IS NOT NULL) LEFT OUTER JOIN "hosts" ON "hosts"."organization_id" = 1 AND "hosts"."location_id" IN (3, 2) AND "hosts"."id" = "template_invocations"."host_id" AND "hosts"."type" = 'Host::Managed' WHERE (("job_invocations"."id" IN (SELECT "job_invocations"."id" FROM         "job_invocations" 
        INNER JOIN "template_invocations" 
        ON "job_invocations"."id" = "template_invocations"."job_invocation_id"  
        INNER JOIN "hosts" 
        ON "template_invocations"."host_id" = "hosts"."id" 
 WHERE "hosts"."name" = 'AWESOME.HOST.NAME' ))) AND "job_invocations"."id" = 111 ORDER BY job_invocations.id DESC -- #<ActiveRecord::Relation []> any: false

Interesting finding:
- I ignore the db transaction and prevent that the rollback is done
- I run the same query as above in a psql shell afterwards, the db returns exactly the necessary data.

I gathered all sql queries:

INSERT INTO targetings (search_query, user_id, targeting_type, created_at, updated_at) VALUES ('name ^ (the.host)', 5, 'static_query', '2021-04-12 14:40:55.388516', '2021-04-12 14:40:55.388516') RETURNING id;

INSERT INTO foreman_tasks_task_groups (type) VALUES ('JobInvocationTaskGroup') RETURNING id;

INSERT INTO foreman_tasks_triggerings (mode, start_at) VALUES ('immediate', '2021-04-12 14:40:55.405063') RETURNING id;

INSERT INTO job_invocations (targeting_id, job_category, task_group_id, triggering_id, description) VALUES (97, 'Commands', 99, 96, 'Run ls -l') RETURNING id;

INSERT INTO template_invocations (template_id, job_invocation_id, effective_user) VALUES (158, 127, 'root') RETURNING id;

SELECT 1 AS one FROM job_invocations LEFT OUTER JOIN template_invocations ON template_invocations.job_invocation_id = job_invocations.id AND (host_id IS NOT NULL) LEFT OUTER JOIN hosts ON hosts.organization_id = 1 AND hosts.location_id IN (3,2) AND hosts.id = template_invocations.host_id AND hosts.type = 'Host::Managed' WHERE ((job_invocations.id IN (SELECT job_invocations.id FROM         job_invocations
        INNER JOIN template_invocations
        ON job_invocations.id = template_invocations.job_invocation_id
        INNER JOIN hosts
        ON template_invocations.host_id = hosts.id
 WHERE hosts.name = 'the.host' ))) AND job_invocations.id = 127 LIMIT 1 ;

The host_id in the template_invocation insert is missing. After changing into to the following, the final SELECT 1 works:

INSERT INTO template_invocations (template_id, job_invocation_id, host_id, effective_user) VALUES (158, 125, 2, 'root') RETURNING id;

Isn't the host missing in:
https://github.com/theforeman/foreman_remote_execution/blob/e1cabc559fa0098812b32e8bb6b5638ed4579dab/app/models/job_invocation_composer.rb#L542

In case of filtering based on create_template_invocations it fails, too:

SELECT 1 AS one FROM "template_invocations" LEFT OUTER JOIN "hosts" ON "hosts"."organization_id" = $1 AND "hosts"."location_id" IN ($2, $3) AND "hosts"."id" = "template_invocations"."host_id" AND "hosts"."type" = $4 WHERE (("hosts"."name" = 'the.host')) AND "template_invocations"."id" = $5 LIMIT $6  [["organization_id", 1], ["location_id", 3], ["location_id", 2], ["type", "Host::Managed"], ["id", 164], ["LIMIT", 1]]

Reason: The host ID in template_invocation is not set:

INSERT INTO "template_invocations" ("template_id", "job_invocation_id", "effective_user") VALUES ($1, $2, $3) RETURNING "id"  [["template_id", 157], ["job_invocation_id", 141], ["effective_user", "root"]]

Then the above SQL SELECT fails because of: "hosts"."id" = "template_invocations"."host_id"

The host_id is set later on:
https://github.com/theforeman/foreman_remote_execution/blob/e1cabc559fa0098812b32e8bb6b5638ed4579dab/app/lib/actions/remote_execution/run_hosts_job.rb#L44

This is to late if the permission validation verifys host.id = template_invocation.host_id much earlier.

I ran into a similar error when configuring restricted role. The `Job invocation` / `execute_jobs_on_infrastructure_hosts` permission is needed in order to allow users to trigger puppet agent runs.