Future job execution executes immediately

Support
1

Problem:
If I schedule a job for future execution (in 10 minutes for example), the job is executed now.

Expected outcome:
Job should start in 10 minutes, not now.

Foreman and Proxy versions:
candlepin-4.1.5-1.el7.noarch
candlepin-selinux-4.1.5-1.el7.noarch
foreman-3.0.0-1.el7.noarch
foreman-cli-3.0.0-1.el7.noarch
foreman-debug-3.0.0-1.el7.noarch
foreman-dynflow-sidekiq-3.0.0-1.el7.noarch
foreman-installer-3.0.0-1.el7.noarch
foreman-installer-katello-3.0.0-1.el7.noarch
foreman-libvirt-3.0.0-1.el7.noarch
foreman-postgresql-3.0.0-1.el7.noarch
foreman-proxy-3.0.0-1.el7.noarch
foreman-release-3.0.0-1.el7.noarch
foreman-selinux-3.0.0-1.el7.noarch
foreman-service-3.0.0-1.el7.noarch
katello-4.2.0.rc1-1.el7.noarch
katello-certs-tools-2.8.0-1.el7.noarch
katello-client-bootstrap-1.7.6-1.el7.noarch
katello-common-4.2.0.rc1-1.el7.noarch
katello-debug-4.2.0.rc1-1.el7.noarch
katello-default-ca-1.0-1.noarch
katello-selinux-4.0.2-1.el7.noarch
katello-server-ca-1.0-1.noarch
pulp-client-1.0-1.noarch
pulpcore-selinux-1.2.5-1.el7.x86_64
python3-pulp-ansible-0.9.0-1.el7.noarch
python3-pulp-certguard-1.4.0-1.el7.noarch
python3-pulp-container-2.7.1-1.el7.noarch
python3-pulp-deb-2.14.1-1.el7.noarch
python3-pulp-file-1.8.2-1.el7.noarch
python3-pulp-rpm-3.14.3-1.el7.noarch
python3-pulpcore-3.14.5-2.el7.noarch
qpid-proton-c-0.34.0-2.el7.x86_64
rubygem-foreman_maintain-0.8.10-1.el7.noarch
tfm-rubygem-actioncable-6.0.3.7-1.el7.noarch
tfm-rubygem-actionmailbox-6.0.3.7-1.el7.noarch
tfm-rubygem-actionmailer-6.0.3.7-1.el7.noarch
tfm-rubygem-actionpack-6.0.3.7-1.el7.noarch
tfm-rubygem-actiontext-6.0.3.7-1.el7.noarch
tfm-rubygem-actionview-6.0.3.7-1.el7.noarch
tfm-rubygem-activejob-6.0.3.7-1.el7.noarch
tfm-rubygem-activemodel-6.0.3.7-1.el7.noarch
tfm-rubygem-activerecord-6.0.3.7-1.el7.noarch
tfm-rubygem-activerecord-import-1.1.0-1.el7.noarch
tfm-rubygem-activerecord-session_store-2.0.0-1.el7.noarch
tfm-rubygem-activestorage-6.0.3.7-1.el7.noarch
tfm-rubygem-activesupport-6.0.3.7-1.el7.noarch
tfm-rubygem-addressable-2.8.0-1.el7.noarch
tfm-rubygem-algebrick-0.7.3-8.el7.noarch
tfm-rubygem-amazing_print-1.1.0-2.el7.noarch
tfm-rubygem-ancestry-3.0.7-2.el7.noarch
tfm-rubygem-anemone-0.7.2-23.el7.noarch
tfm-rubygem-angular-rails-templates-1.1.0-2.el7.noarch
tfm-rubygem-ansi-1.5.0-3.el7.noarch
tfm-rubygem-apipie-bindings-0.4.0-2.el7.noarch
tfm-rubygem-apipie-dsl-2.4.0-1.el7.noarch
tfm-rubygem-apipie-params-0.0.5-5.el7.noarch
tfm-rubygem-apipie-rails-0.5.17-4.el7.noarch
tfm-rubygem-audited-4.9.0-4.el7.noarch
tfm-rubygem-bcrypt-3.1.12-4.el7.x86_64
tfm-rubygem-builder-3.2.4-2.el7.noarch
tfm-rubygem-bundler_ext-0.4.1-6.el7.noarch
tfm-rubygem-clamp-1.1.2-7.el7.noarch
tfm-rubygem-colorize-0.8.1-2.el7.noarch
tfm-rubygem-concurrent-ruby-1.1.6-3.el7.noarch
tfm-rubygem-concurrent-ruby-edge-0.6.0-3.fm2_5.el7.noarch
tfm-rubygem-connection_pool-2.2.2-3.el7.noarch
tfm-rubygem-crass-1.0.6-2.el7.noarch
tfm-rubygem-css_parser-1.4.7-5.el7.noarch
tfm-rubygem-daemons-1.2.3-7.el7.noarch
tfm-rubygem-deacon-1.0.0-5.el7.noarch
tfm-rubygem-deep_cloneable-3.0.0-4.el7.noarch
tfm-rubygem-deface-1.5.3-3.el7.noarch
tfm-rubygem-domain_name-0.5.20160310-5.el7.noarch
tfm-rubygem-dynflow-1.5.0-1.fm2_6.el7.noarch
tfm-rubygem-erubi-1.9.0-2.el7.noarch
tfm-rubygem-excon-0.76.0-2.el7.noarch
tfm-rubygem-facter-4.0.51-2.el7.x86_64
tfm-rubygem-faraday-0.17.3-2.el7.noarch
tfm-rubygem-fast_gettext-1.4.1-5.el7.noarch
tfm-rubygem-ffi-1.12.2-2.el7.x86_64
tfm-rubygem-fog-core-2.1.0-4.el7.noarch
tfm-rubygem-fog-json-1.2.0-4.el7.noarch
tfm-rubygem-fog-libvirt-0.9.0-1.el7.noarch
tfm-rubygem-fog-xml-0.1.2-9.el7.noarch
tfm-rubygem-foreman-tasks-5.1.0-1.fm3_0.el7.noarch
tfm-rubygem-foreman_puppet-1.0.1-1.fm3_0.el7.noarch
tfm-rubygem-foreman_remote_execution-4.7.0-1.fm3_0.el7.noarch
tfm-rubygem-formatador-0.2.1-13.el7.noarch
tfm-rubygem-friendly_id-5.3.0-2.el7.noarch
tfm-rubygem-fx-0.5.0-2.el7.noarch
tfm-rubygem-get_process_mem-0.2.7-2.el7.noarch
tfm-rubygem-gettext_i18n_rails-1.8.0-3.el7.noarch
tfm-rubygem-gitlab-sidekiq-fetcher-0.6.0-2.el7.noarch
tfm-rubygem-globalid-0.4.2-2.el7.noarch
tfm-rubygem-graphql-1.8.14-3.el7.noarch
tfm-rubygem-graphql-batch-0.3.10-3.el7.noarch
tfm-rubygem-gssapi-1.2.0-8.el7.noarch
tfm-rubygem-hammer_cli-3.0.0-1.el7.noarch
tfm-rubygem-hammer_cli_foreman-3.0.0-1.el7.noarch
tfm-rubygem-hammer_cli_foreman_puppet-0.0.3-1.fm3_0.el7.noarch
tfm-rubygem-hammer_cli_foreman_remote_execution-0.2.2-1.fm3_0.el7.noarch
tfm-rubygem-hammer_cli_foreman_tasks-0.0.16-1.fm3_0.el7.noarch
tfm-rubygem-hammer_cli_katello-1.1.2-1.el7.noarch
tfm-rubygem-hashie-3.6.0-3.el7.noarch
tfm-rubygem-highline-2.0.3-2.el7.noarch
tfm-rubygem-hocon-1.3.1-2.el7.noarch
tfm-rubygem-http-cookie-1.0.2-5.el7.noarch
tfm-rubygem-i18n-1.8.2-2.el7.noarch
tfm-rubygem-jwt-2.2.2-2.el7.noarch
tfm-rubygem-kafo-6.4.0-1.el7.noarch
tfm-rubygem-kafo_parsers-1.2.1-1.el7.noarch
tfm-rubygem-kafo_wizards-0.0.2-2.el7.noarch
tfm-rubygem-katello-4.2.0.rc1-1.el7.noarch
tfm-rubygem-ldap_fluff-0.6.0-1.el7.noarch
tfm-rubygem-little-plugger-1.1.4-3.el7.noarch
tfm-rubygem-locale-2.0.9-15.el7.noarch
tfm-rubygem-logging-2.3.0-2.el7.noarch
tfm-rubygem-loofah-2.4.0-2.el7.noarch
tfm-rubygem-mail-2.7.1-2.el7.noarch
tfm-rubygem-marcel-1.0.1-1.el7.noarch
tfm-rubygem-method_source-0.9.2-3.el7.noarch
tfm-rubygem-mime-types-3.3.1-2.el7.noarch
tfm-rubygem-mime-types-data-3.2018.0812-5.el7.noarch
tfm-rubygem-mini_mime-1.0.2-2.el7.noarch
tfm-rubygem-mini_portile2-2.5.1-1.el7.noarch
tfm-rubygem-multi_json-1.14.1-3.el7.noarch
tfm-rubygem-multipart-post-2.0.0-3.el7.noarch
tfm-rubygem-mustermann-1.1.1-1.el7.noarch
tfm-rubygem-net-ldap-0.17.0-2.el7.noarch
tfm-rubygem-net-ping-2.0.1-5.el7.noarch
tfm-rubygem-net-scp-1.2.1-5.el7.noarch
tfm-rubygem-net-ssh-4.2.0-3.el7.noarch
tfm-rubygem-net_http_unix-0.2.2-2.el7.noarch
tfm-rubygem-netrc-0.11.0-6.el7.noarch
tfm-rubygem-nio4r-2.5.4-2.el7.x86_64
tfm-rubygem-nokogiri-1.11.3-2.el7.x86_64
tfm-rubygem-oauth-0.5.4-5.el7.noarch
tfm-rubygem-parallel-1.19.1-2.el7.noarch
tfm-rubygem-parse-cron-0.1.4-5.fm2_5.el7.noarch
tfm-rubygem-pg-1.1.4-4.el7.x86_64
tfm-rubygem-polyglot-0.3.5-3.el7.noarch
tfm-rubygem-powerbar-2.0.1-3.el7.noarch
tfm-rubygem-promise.rb-0.7.4-3.el7.noarch
tfm-rubygem-public_suffix-3.0.3-3.el7.noarch
tfm-rubygem-pulp_ansible_client-0.8.0-1.el7.noarch
tfm-rubygem-pulp_certguard_client-1.4.0-1.el7.noarch
tfm-rubygem-pulp_container_client-2.7.0-1.el7.noarch
tfm-rubygem-pulp_deb_client-2.13.0-1.el7.noarch
tfm-rubygem-pulp_file_client-1.8.1-1.el7.noarch
tfm-rubygem-pulp_python_client-3.4.0-1.el7.noarch
tfm-rubygem-pulp_rpm_client-3.13.3-1.el7.noarch
tfm-rubygem-pulpcore_client-3.14.1-1.el7.noarch
tfm-rubygem-puma-5.3.2-1.el7.x86_64
tfm-rubygem-puma-status-1.3-1.el7.noarch
tfm-rubygem-qpid_proton-0.34.0-3.el7.x86_64
tfm-rubygem-rabl-0.14.3-2.el7.noarch
tfm-rubygem-racc-1.5.2-1.el7.x86_64
tfm-rubygem-rack-2.2.3-2.el7.noarch
tfm-rubygem-rack-cors-1.0.2-3.el7.noarch
tfm-rubygem-rack-jsonp-1.3.1-10.el7.noarch
tfm-rubygem-rack-protection-2.1.0-2.el7.noarch
tfm-rubygem-rack-test-1.1.0-5.el7.noarch
tfm-rubygem-rails-6.0.3.7-1.el7.noarch
tfm-rubygem-rails-dom-testing-2.0.3-7.el7.noarch
tfm-rubygem-rails-html-sanitizer-1.3.0-2.el7.noarch
tfm-rubygem-rails-i18n-6.0.0-3.el7.noarch
tfm-rubygem-railties-6.0.3.7-1.el7.noarch
tfm-rubygem-rainbow-2.2.2-1.el7.noarch
tfm-rubygem-rb-inotify-0.9.7-6.el7.noarch
tfm-rubygem-record_tag_helper-1.0.1-4.el7.noarch
tfm-rubygem-redfish_client-0.5.2-2.el7.noarch
tfm-rubygem-redis-4.1.2-3.el7.noarch
tfm-rubygem-responders-3.0.0-4.el7.noarch
tfm-rubygem-rest-client-2.0.2-4.el7.noarch
tfm-rubygem-rkerberos-0.1.5-20.el7.x86_64
tfm-rubygem-roadie-3.4.0-4.el7.noarch
tfm-rubygem-roadie-rails-2.1.1-3.el7.noarch
tfm-rubygem-robotex-1.0.0-22.el7.noarch
tfm-rubygem-rsec-0.4.3-5.el7.noarch
tfm-rubygem-ruby-libvirt-0.7.1-2.el7.x86_64
tfm-rubygem-ruby2_keywords-0.0.4-1.el7.noarch
tfm-rubygem-ruby2ruby-2.4.2-4.el7.noarch
tfm-rubygem-ruby_parser-3.10.1-4.el7.noarch
tfm-rubygem-rubyipmi-0.10.0-7.el7.noarch
tfm-rubygem-runcible-2.13.1-2.el7.noarch
tfm-rubygem-safemode-1.3.6-2.el7.noarch
tfm-rubygem-scoped_search-4.1.9-2.el7.noarch
tfm-rubygem-sd_notify-0.1.0-2.el7.noarch
tfm-rubygem-secure_headers-6.3.0-3.el7.noarch
tfm-rubygem-sequel-5.42.0-2.el7.noarch
tfm-rubygem-server_sent_events-0.1.2-2.el7.noarch
tfm-rubygem-sexp_processor-4.10.0-7.el7.noarch
tfm-rubygem-sidekiq-5.2.7-4.el7.noarch
tfm-rubygem-sinatra-2.1.0-2.el7.noarch
tfm-rubygem-smart_proxy_dynflow-0.5.2-2.fm2_6.el7.noarch
tfm-rubygem-smart_proxy_dynflow_core-0.4.1-1.fm2_6.el7.noarch
tfm-rubygem-smart_proxy_pulp-3.1.0-1.fm2_6.el7.noarch
tfm-rubygem-smart_proxy_remote_execution_ssh-0.4.1-2.fm2_6.el7.noarch
tfm-rubygem-sprockets-4.0.2-2.el7.noarch
tfm-rubygem-sprockets-rails-3.2.1-7.el7.noarch
tfm-rubygem-sqlite3-1.3.13-7.el7.x86_64
tfm-rubygem-sshkey-1.9.0-5.el7.noarch
tfm-rubygem-statsd-instrument-2.1.4-4.el7.noarch
tfm-rubygem-stomp-1.4.9-2.el7.noarch
tfm-rubygem-thor-1.0.1-3.el7.noarch
tfm-rubygem-thread_safe-0.3.6-6.el7.noarch
tfm-rubygem-tilt-2.0.8-5.el7.noarch
tfm-rubygem-tzinfo-1.2.6-2.el7.noarch
tfm-rubygem-unf-0.1.3-9.el7.noarch
tfm-rubygem-unf_ext-0.0.7.2-4.el7.x86_64
tfm-rubygem-unicode-0.4.4.4-4.el7.x86_64
tfm-rubygem-unicode-display_width-1.7.0-2.el7.noarch
tfm-rubygem-validates_lengths_from_database-0.5.0-8.el7.noarch
tfm-rubygem-webpack-rails-0.9.8-6.el7.noarch
tfm-rubygem-websocket-driver-0.7.1-2.el7.x86_64
tfm-rubygem-websocket-extensions-0.1.5-2.el7.noarch
tfm-rubygem-will_paginate-3.1.7-4.el7.noarch
tfm-rubygem-xmlrpc-0.3.0-3.el7.noarch
tfm-rubygem-zeitwerk-2.2.2-2.el7.noarch
tfm-runtime-7.0-4.el7.x86_64

Distribution and version:
CentOS 7 latest update (today)

Other relevant data:

Log output:

Oct 14 11:12:04 update01.bn.10.ash-b.prod.bn-lx.rz dynflow-sidekiq@worker-1[14687]: /usr/share/foreman/lib/proxy_api/resource.rb:72: warning: URI.escape is obsolete
Oct 14 11:12:04 update01.bn.10.ash-b.prod.bn-lx.rz smart-proxy[14801]: 10.150.1.48 - - [14/Oct/2021:11:12:04 CEST] "GET /dynflow/tasks/count?state=running HTTP/1.1" 200 29
Oct 14 11:12:04 update01.bn.10.ash-b.prod.bn-lx.rz smart-proxy[14801]: - -> /dynflow/tasks/count?state=running
Oct 14 11:12:05 update01.bn.10.ash-b.prod.bn-lx.rz smart-proxy[14801]: 10.150.1.48 - - [14/Oct/2021:11:12:05 CEST] "POST /dynflow/tasks/launch HTTP/1.1" 200 110
Oct 14 11:12:05 update01.bn.10.ash-b.prod.bn-lx.rz smart-proxy[14801]: - -> /dynflow/tasks/launch
Oct 14 11:12:05 update01.bn.10.ash-b.prod.bn-lx.rz smart-proxy[14801]: :paranoid is deprecated, please use :verify_host_key. Supported values are exactly the same, only the name of the option has changed.

Its a really simple job, that executes an echo with hostnamectl on the destionation host and shows the output. If a commit a time in future and click submit, the “Schedule” time is now instead of a given date.

Thank you

2

Hi, does it also execute immediatelly if you schedule it for a more distant future (the next day or so)? And as a followup question, what are the timezones configured for the server and for the client (your browser)?

3

I saw, there was Foreman 3.0 and Katello 4.0 on the system. I do not know, how this happens, but after updating the system to Katello 4.2, anything does not work anymore.

To answer your questions: Same behaviour with more distant future schedule and Europe/Berlin was the timezone for client and server.

A new installation is running. I will report after some testing.

4

I installed a fresh katello 4.2 and it is the same behaviour. If I configure it to run tomorrow or in a month, scheduling runs immediately. The timezone on every client is “CET” (Europe/Berlin)

After clicking save, the webui shows me, it should start now. This seems strange. Do you have an idea?

5

After clicking on “Submit” to apply my future schedule, the website logs following:

2021-11-18T16:25:49 [I|app|f7c92f93] Started POST "/job_invocations" for 10.2.150.3 at 2021-11-18 16:25:49 +0100                                                                                                                                               
2021-11-18T16:25:49 [I|app|f7c92f93] Processing by JobInvocationsController#create as HTML                                                                                                                                                                     
2021-11-18T16:25:49 [I|app|f7c92f93]   Parameters: {"utf8"=>"✓", "authenticity_token"=>"DFlIGvW3uSSGWl+LRj9VQfmNze4r37948f0wer4+VOfEBqJ17NRmt+0pYwUpzcfXV0gAebtjZ18n51fTvb+nkg==", "job_invocation"=>{"job_category"=>"BN", "remote_execution_feature_id"=>"", 
"providers"=>{"SSH"=>{"job_template_id"=>"160", "job_templates"=>{"160"=>{"effective_user"=>"root", "execution_timeout_interval"=>""}}}}, "description"=>"", "description_override"=>"Verbindungstest, ob alle Hosts erreicht werden können", "description_form
at"=>"Verbindungstest, ob alle Hosts erreicht werden können", "password"=>"[FILTERED]", "key_passphrase"=>"", "effective_user_password"=>"[FILTERED]", "concurrency_level"=>"", "time_span"=>""}, "targeting"=>{"bookmark_id"=>"", "search_query"=>"name ^ (mai
l01l.kba.11.ash-b.prod.bn.rz)", "randomized_ordering"=>"false", "targeting_type"=>"static_query"}, "fakepassword"=>"[FILTERED]", "triggering"=>{"mode"=>"future", "start_at_raw"=>"2021-11-18 16:25", "start_before_raw"=>"", "input_type"=>"daily", "cronline"
=>"", "days"=>"", "days_of_week"=>{"1"=>"0", "2"=>"0", "3"=>"0", "4"=>"0", "5"=>"0", "6"=>"0", "7"=>"0"}, "time"=>{"time(1i)"=>"2021", "time(2i)"=>"11", "time(3i)"=>"18", "time(4i)"=>"16", "time(5i)"=>"25"}, "max_iteration"=>"", "end_time_limited"=>"false
", "end_time"=>{"end_time(1i)"=>"2021", "end_time(2i)"=>"11", "end_time(3i)"=>"18", "end_time(4i)"=>"16", "end_time(5i)"=>"25"}, "purpose"=>""}, "commit"=>"Submit"}

I configured to run an 2021-11-20, but it logs 2021-11-18. So I think, there is something wrong.

6

I opened a bug report: Bug #34028: Job scheduler runs immediately (not on scheduled time) - Katello - Foreman

7

We were dealing with this in another thread, hopefully it is the same bug.

8

I confirm it is fixed. Thanks for your great work!