Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

ZD : 16.5.x nodes are reporting a handler error when run as systemd service #10565

Closed
dheerajd-msys opened this issue Oct 28, 2020 · 11 comments
Closed

ZD : 16.5.x nodes are reporting a handler error when run as systemd service #10565

dheerajd-msys opened this issue Oct 28, 2020 · 11 comments
Assignees
@dheerajd-msys @kvivek1115
Labels
Status: Untriaged An issue that has yet to be triaged.

Comments

@dheerajd-msys
Copy link
Contributor

Description

Nodes are receiving the below error when reaching the audit handler portion only when chef-client is initiated from the systemctl service. They work fine when run manually as root.

2020-10-14T20:48:40.999279+00:00 ip-10-30-15-71 chef-client[7187]: Running handlers:
2020-10-14T20:48:41.377744+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: Report handler Chef::Handler::AuditReport raised #<ArgumentError: couldn't find login name -- expanding `~'>
2020-10-14T20:48:41.378000+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-0.13.1/lib/pry/config.rb:314:in `expand_path'
2020-10-14T20:48:41.378129+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-0.13.1/lib/pry/config.rb:314:in `default_rc_file'
2020-10-14T20:48:41.378249+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-0.13.1/lib/pry/config.rb:187:in `initialize'
2020-10-14T20:48:41.378366+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-0.13.1/lib/pry/pry_class.rb:327:in `new'
2020-10-14T20:48:41.378482+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-0.13.1/lib/pry/pry_class.rb:327:in `reset_defaults'
2020-10-14T20:48:41.378607+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-0.13.1/lib/pry/pry_class.rb:337:in `init'
2020-10-14T20:48:41.378725+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-0.13.1/lib/pry/pry_class.rb:388:in `<top (required)>'
2020-10-14T20:48:41.378851+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
2020-10-14T20:48:41.378965+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
2020-10-14T20:48:41.379078+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-0.13.1/lib/pry.rb:61:in `<top (required)>'
2020-10-14T20:48:41.379191+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
2020-10-14T20:48:41.379311+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
2020-10-14T20:48:41.379425+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/inspec-core-4.23.4/lib/inspec/shell.rb:1:in `<top (required)>'
2020-10-14T20:48:41.379539+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
2020-10-14T20:48:41.379682+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
2020-10-14T20:48:41.379803+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/inspec-core-4.23.4/lib/inspec.rb:13:in `<top (required)>'
2020-10-14T20:48:41.379917+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
2020-10-14T20:48:41.380029+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
2020-10-14T20:48:41.380141+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /C:#010ef#001che/cookbooks/audit/files/default/handler/audit_report.rb:121:in `load_needed_dependencies'
2020-10-14T20:48:41.380254+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /C:#010ef#001che/cookbooks/audit/files/default/handler/audit_report.rb:56:in `report'
2020-10-14T20:48:41.380367+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/handler.rb:258:in `run_report_unsafe'
2020-10-14T20:48:41.380479+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /C:#010ef#001che/cookbooks/audit/files/default/handler/audit_report.rb:100:in `run_report_safely'
2020-10-14T20:48:41.380593+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/handler.rb:123:in `block in run_report_handlers'
2020-10-14T20:48:41.380718+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/handler.rb:121:in `each'
2020-10-14T20:48:41.380844+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/handler.rb:121:in `run_report_handlers'
2020-10-14T20:48:41.380954+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/handler.rb:133:in `block in <class:Handler>'
2020-10-14T20:48:41.381065+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/client.rb:427:in `block in run_completed_successfully'
2020-10-14T20:48:41.381176+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/client.rb:426:in `each'
2020-10-14T20:48:41.381286+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/client.rb:426:in `run_completed_successfully'
2020-10-14T20:48:41.381431+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/client.rb:291:in `run'
2020-10-14T20:48:41.381551+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/application.rb:323:in `block in fork_chef_client'
2020-10-14T20:48:41.389698+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/application.rb:311:in `fork'
2020-10-14T20:48:41.389907+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/application.rb:311:in `fork_chef_client'
2020-10-14T20:48:41.390087+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/application.rb:276:in `block in run_chef_client'
2020-10-14T20:48:41.390254+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/local_mode.rb:42:in `with_server_connectivity'
2020-10-14T20:48:41.390421+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/application.rb:264:in `run_chef_client'
2020-10-14T20:48:41.390580+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/application/base.rb:403:in `sleep_then_run_chef_client'
2020-10-14T20:48:41.390742+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/application/base.rb:392:in `block in interval_run_chef_client'
2020-10-14T20:48:41.390899+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/application/base.rb:391:in `loop'
2020-10-14T20:48:41.391055+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/application/base.rb:391:in `interval_run_chef_client'
2020-10-14T20:48:41.391210+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/application/base.rb:344:in `run_application'
2020-10-14T20:48:41.391365+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/application.rb:67:in `run'
2020-10-14T20:48:41.391520+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-bin-16.5.64/bin/chef-client:25:in `<top (required)>'
2020-10-14T20:48:41.391698+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/bin/chef-client:156:in `load'
2020-10-14T20:48:41.391868+00:00 ip-10-30-15-71 chef-client[7187]: [2020-10-14T20:48:41+00:00] ERROR: /opt/chef/bin/chef-client:156:in `<main>'
2020-10-14T20:48:41.392024+00:00 ip-10-30-15-71 chef-client[7187]:   - Chef::Handler::AuditReport
2020-10-14T20:48:41.392177+00:00 ip-10-30-15-71 chef-client[7187]: Running handlers complete
2020-10-14T20:48:41.392331+00:00 ip-10-30-15-71 chef-client[7187]: Chef Infra Client finished, 0/119 resources updated in 31 seconds

Chef Version

16.5.x

Platform Version

Replication Case

Install/configure Chef Infra Client 16.5.64 or 16.5.77 under systemd on a node with has audit/compliance reporting enabled

Client Output

Expected Behaviour

Chef Infra Client sends audit/compliance report to Automate successfully

Actual Behaviour

Bundled Inspec reports following error

ArgumentError: couldn't find login name -- expanding `~'

And client run fails.

Stacktrace
@dheerajd-msys dheerajd-msys added the Status: Untriaged An issue that has yet to be triaged. label Oct 28, 2020
@dheerajd-msys dheerajd-msys self-assigned this Oct 28, 2020
@lamont-granquist
Copy link
Contributor

That looks like an audit cookbook bug and not a chef-client bug

@srb3
Copy link

srb3 commented Nov 4, 2020

@lamont-granquist I have a customer that is using the same version of the audit cookbook (v9.4.0), but gets this error when they upgrade to chef client 16.5.77 from 16.2.50

@collinmcneese
Copy link
Contributor

collinmcneese commented Nov 5, 2020 •
edited

I ran in to this as well and confirmed the results in a local A2 vagrant setup. Looks like 16.4.41 is working fine but 16.5.64 introduces the error.

-- Unit chef-client.service has finished starting up.
Nov 05 18:44:21 system1 chef-client[196071]: Starting Chef Infra Client, version 16.5.64
Nov 05 18:44:21 system1 chef-client[196071]: Patents: https://www.chef.io/patents
Nov 05 18:44:23 system1 chef-client[196071]: Using policy 'inspec_policy' at revision '1bd5f376c34afae36a91401d9ea02752340903b6e14e1cf3554d0a1a362819f5'
Nov 05 18:44:23 system1 chef-client[196071]: resolving cookbooks for run list: ["cookbook_1::default@0.1.2 (7a45f7c)", "inspec::default@0.1.10 (887111c)"]
Nov 05 18:44:23 system1 chef-client[196071]: Synchronizing Cookbooks:
Nov 05 18:44:23 system1 chef-client[196071]:   - audit (9.5.0)
Nov 05 18:44:23 system1 chef-client[196071]:   - chef-client (12.3.3)
Nov 05 18:44:23 system1 chef-client[196071]:   - cookbook_1 (0.1.2)
Nov 05 18:44:23 system1 chef-client[196071]:   - cron (6.3.1)
Nov 05 18:44:23 system1 chef-client[196071]:   - inspec (0.1.10)
Nov 05 18:44:23 system1 chef-client[196071]:   - logrotate (2.2.3)
Nov 05 18:44:23 system1 chef-client[196071]: Installing Cookbook Gems:
Nov 05 18:44:23 system1 chef-client[196071]: Compiling Cookbooks...
Nov 05 18:44:23 system1 chef-client[196071]: Recipe: audit::inspec
Nov 05 18:44:23 system1 chef-client[196071]:   * inspec_gem[inspec] action install (up to date)
Nov 05 18:44:23 system1 chef-client[196071]:   Converging 17 resources
Nov 05 18:44:23 system1 chef-client[196071]: Recipe: cookbook_1::default
Nov 05 18:44:23 system1 chef-client[196071]:   * ruby_block[puts] action runrunning cookbook_1
Nov 05 18:44:23 system1 chef-client[196071]:     - execute the ruby block puts
Nov 05 18:44:23 system1 chef-client[196071]: Recipe: chef-client::config
Nov 05 18:44:23 system1 chef-client[196071]:   * logrotate_app[chef-client] action enable
Nov 05 18:44:23 system1 chef-client[196071]:     * directory[/etc/logrotate.d] action create (up to date)
Nov 05 18:44:23 system1 chef-client[196071]:     * template[/etc/logrotate.d/chef-client] action create (up to date)
Nov 05 18:44:23 system1 chef-client[196071]:      (up to date)
Nov 05 18:44:23 system1 chef-client[196071]:   * directory[/var/run/chef] action create (up to date)
Nov 05 18:44:23 system1 chef-client[196071]:   * directory[/var/lib/chef] action create (up to date)
Nov 05 18:44:23 system1 chef-client[196071]:   * directory[/var/log/chef] action create (up to date)
Nov 05 18:44:23 system1 chef-client[196071]:   * directory[/etc/chef] action create (up to date)
Nov 05 18:44:23 system1 chef-client[196071]:   * file[/var/log/chef/client.log] action create (up to date)
Nov 05 18:44:23 system1 chef-client[196071]:   * template[/etc/chef/client.rb] action create (up to date)
Nov 05 18:44:23 system1 chef-client[196071]:   * directory[/etc/chef/client.d] action create (up to date)
Nov 05 18:44:23 system1 chef-client[196071]:   * ruby_block[reload_client_config] action nothing (skipped due to action :nothing)
Nov 05 18:44:23 system1 chef-client[196071]: Recipe: chef-client::systemd_service
Nov 05 18:44:23 system1 chef-client[196071]:   * template[/etc/sysconfig/chef-client] action create (up to date)
Nov 05 18:44:23 system1 chef-client[196071]:   * directory[/etc/systemd/system] action create (up to date)
Nov 05 18:44:23 system1 chef-client[196071]:   * systemd_unit[chef-client.service] action create (up to date)
Nov 05 18:44:24 system1 chef-client[196071]:   * systemd_unit[chef-client.timer] action stop (up to date)
Nov 05 18:44:24 system1 chef-client[196071]:   * systemd_unit[chef-client.timer] action disable (up to date)
Nov 05 18:44:24 system1 chef-client[196071]:   * systemd_unit[chef-client.timer] action delete (up to date)
Nov 05 18:44:24 system1 chef-client[196071]:   * service[chef-client] action enable (up to date)
Nov 05 18:44:24 system1 chef-client[196071]:   * service[chef-client] action start (up to date)
Nov 05 18:44:24 system1 chef-client[196071]: Recipe: audit::inspec
Nov 05 18:44:24 system1 chef-client[196071]:   * inspec_gem[inspec] action nothing (skipped due to action :nothing)
Nov 05 18:44:24 system1 chef-client[196071]: Recipe: inspec::default
Nov 05 18:44:24 system1 chef-client[196071]:   * cookbook_file[/var/chef/waiver_file.yml] action create (up to date)
Nov 05 18:44:24 system1 chef-client[196071]: Running handlers:
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: Report handler Chef::Handler::AuditReport raised #<ArgumentError: couldn't find login name -- expanding `~'>
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-0.13.1/lib/pry/config.rb:314:in `expand_path'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-0.13.1/lib/pry/config.rb:314:in `default_rc_file'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-0.13.1/lib/pry/config.rb:187:in `initialize'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-0.13.1/lib/pry/pry_class.rb:327:in `new'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-0.13.1/lib/pry/pry_class.rb:327:in `reset_defaults'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-0.13.1/lib/pry/pry_class.rb:337:in `init'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-0.13.1/lib/pry/pry_class.rb:388:in `<top (required)>'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-0.13.1/lib/pry.rb:61:in `<top (required)>'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/inspec-core-4.23.4/lib/inspec/shell.rb:1:in `<top (required)>'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/inspec-core-4.23.4/lib/inspec.rb:13:in `<top (required)>'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /var/chef/cache/cookbooks/audit/files/default/handler/audit_report.rb:121:in `load_needed_dependencies'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /var/chef/cache/cookbooks/audit/files/default/handler/audit_report.rb:56:in `report'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/handler.rb:258:in `run_report_unsafe'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /var/chef/cache/cookbooks/audit/files/default/handler/audit_report.rb:100:in `run_report_safely'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/handler.rb:123:in `block in run_report_handlers'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/handler.rb:121:in `each'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/handler.rb:121:in `run_report_handlers'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/handler.rb:133:in `block in <class:Handler>'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/client.rb:427:in `block in run_completed_successfully'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/client.rb:426:in `each'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/client.rb:426:in `run_completed_successfully'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/client.rb:291:in `run'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/application.rb:323:in `block in fork_chef_client'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/application.rb:311:in `fork'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/application.rb:311:in `fork_chef_client'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/application.rb:276:in `block in run_chef_client'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/local_mode.rb:42:in `with_server_connectivity'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/application.rb:264:in `run_chef_client'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/application/base.rb:403:in `sleep_then_run_chef_client'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/application/base.rb:392:in `block in interval_run_chef_client'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/application/base.rb:391:in `loop'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/application/base.rb:391:in `interval_run_chef_client'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/application/base.rb:344:in `run_application'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.5.64/lib/chef/application.rb:67:in `run'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-bin-16.5.64/bin/chef-client:25:in `<top (required)>'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/bin/chef-client:156:in `load'
Nov 05 18:44:24 system1 chef-client[196071]: [2020-11-05T18:44:24+00:00] ERROR: /opt/chef/bin/chef-client:156:in `<main>'
Nov 05 18:44:24 system1 chef-client[196071]:   - Chef::Handler::AuditReport
Nov 05 18:44:24 system1 chef-client[196071]: Running handlers complete
Nov 05 18:44:24 system1 chef-client[196071]: Chef Infra Client finished, 1/23 resources updated in 03 seconds

@srb3
Copy link

srb3 commented Nov 6, 2020

Some images to support this:
5 clients with different chef client versions, running audit cookbook pulling a inspec profile from chef automate
Selection_342
Compliance results:
Selection_343
Details of failing node:
Selection_344

@dheerajd-msys
Copy link
Contributor Author

Hello @collinmcneese @srb3 I tried to reproduce this issue from my end but no such error as in your logs.
Please check and confirm if there is anything missing.

knife bootstrap 18.222.176.255 -U ubuntu -N ddubey-ubu-msys-audit -r recipe[audit],recipe[chef-client] -c /home/dheerajdubey/Downloads/chef-repo/.chef/knife.rb -VV --sudo --use-sudo-password


 [18.222.176.255] [2020-11-06T07:31:17+00:00] DEBUG: Platform is ubuntu version 18.04
 [18.222.176.255] [2020-11-06T07:31:17+00:00] INFO: Run List is [recipe[audit], recipe[chef-client]]
 [18.222.176.255] [2020-11-06T07:31:17+00:00] INFO: Run List expands to [audit, chef-client]
 [18.222.176.255] [2020-11-06T07:31:17+00:00] INFO: Starting Chef Infra Client Run for ddubey-ubu-msys-audit
 [18.222.176.255] [2020-11-06T07:31:17+00:00] INFO: Running start handlers
 [18.222.176.255] [2020-11-06T07:31:17+00:00] INFO: Start handlers complete.
 [18.222.176.255] [2020-11-06T07:31:17+00:00] DEBUG: Error while reporting run start to Data Collector. URL: https://api.chef.io/organizations/msystech/data-collector Exception: 404 -- 404 "Not Found"  (This is normal if you do not have Chef Automate)
 [18.222.176.255] resolving cookbooks for run list: ["audit", "chef-client"]
 [18.222.176.255] 
 [18.222.176.255] [2020-11-06T07:31:17+00:00] INFO: Loading cookbooks [audit@9.5.0, chef-client@12.3.3, cron@5.0.1, logrotate@2.2.0]
 [18.222.176.255] Synchronizing Cookbooks:
 [18.222.176.255] 
 O: Storing updated cookbooks/chef-client/recipes/service.rb in the cache.
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: Storing updated cookbooks/audit/libraries/helper.rb in the cache.
  -

 [18.222.176.255] 
 [18.222.176.255] [2020-11-06T07:31:18+00:00] DEBUG: Cookbooks to compile: [:audit, :cron, :logrotate, :"chef-client"]
 [18.222.176.255] [2020-11-06T07:31:18+00:00] WARN: Resource cron_d built into Chef Infra Client is being overridden by the resource from a cookbook. Please upgrade your cookbook or remove the cookbook from your run_list.
 [18.222.176.255] Recipe: audit::inspec
 [18.222.176.255] 
 [18.222.176.255]   
 [18.222.176.255] * inspec_gem[inspec] action install
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: Processing inspec_gem[inspec] action install (audit::inspec line 20)
 [18.222.176.255] [2020-11-06T07:31:18+00:00] WARN: inspec_gem: Chef Infra Client >= 15 detected, can only use the embedded InSpec gem!!!
 [18.222.176.255] [2020-11-06T07:31:18+00:00] DEBUG: Installed Chef-InSpec version: 4.23.11
 [18.222.176.255] [2020-11-06T07:31:18+00:00] WARN: inspec_gem: not installing Chef-InSpec. Requested version 4.22 is not compatible with chef-client 16.6.14
 [18.222.176.255]  (up to date)
 [18.222.176.255] 
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: loading handler from /home/dheerajdubey/.chef/cache/cookbooks/audit/files/default/handler/audit_report
 [18.222.176.255] [2020-11-06T07:31:18+00:00] DEBUG: Using chef-client bin from node attributes
 [18.222.176.255] [2020-11-06T07:31:18+00:00] DEBUG: Using chef-client binary at /opt/chef/bin/chef-client
 [18.222.176.255]   
 [18.222.176.255] Converging 10 resources
 [18.222.176.255] 
 [18.222.176.255] [2020-11-06T07:31:18+00:00] DEBUG: Converging node ddubey-ubu-msys-audit
 [18.222.176.255]   
 [18.222.176.255] * inspec_gem[inspec] action nothing
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: Processing inspec_gem[inspec] action nothing (audit::inspec line 20)
 [18.222.176.255]  (skipped due to action :nothing)
 [18.222.176.255] 
 [18.222.176.255] [2020-11-06T07:31:18+00:00] DEBUG: Skipping inspec_gem[inspec] due to action :nothing
 [18.222.176.255] Recipe: chef-client::systemd_service
 [18.222.176.255] 
 [18.222.176.255]   
 [18.222.176.255] * directory[/var/run/chef] action create
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: Processing directory[/var/run/chef] action create (chef-client::systemd_service line 241)
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: directory[/var/run/chef] created directory /var/run/chef
 [18.222.176.255] 
 [18.222.176.255]     
 [18.222.176.255] - create new directory /var/run/chef
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: directory[/var/run/chef] owner changed to 0
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: directory[/var/run/chef] group changed to 0
 [18.222.176.255] 
 [18.222.176.255]     
 [18.222.176.255] - change owner from '' to 'root'
 [18.222.176.255] 
 [18.222.176.255]     
 [18.222.176.255] - change group from '' to 'root'
 [18.222.176.255] 
 [18.222.176.255]   
 [18.222.176.255] * directory[/var/lib/chef] action create
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: Processing directory[/var/lib/chef] action create (chef-client::systemd_service line 241)
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: directory[/var/lib/chef] created directory /var/lib/chef
 [18.222.176.255] 
 [18.222.176.255]     
 [18.222.176.255] - create new directory /var/lib/chef
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: directory[/var/lib/chef] owner changed to 0
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: directory[/var/lib/chef] group changed to 0
 [18.222.176.255] 
 [18.222.176.255]     
 [18.222.176.255] - change owner from '' to 'root'
 [18.222.176.255] 
 [18.222.176.255]     
 [18.222.176.255] - change group from '' to 'root'
 [18.222.176.255] 
 [18.222.176.255]   
 [18.222.176.255] * directory[/var/log/chef] action create
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: Processing directory[/var/log/chef] action create (chef-client::systemd_service line 241)
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: directory[/var/log/chef] created directory /var/log/chef
 [18.222.176.255] 
 [18.222.176.255]     
 [18.222.176.255] - create new directory /var/log/chef
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: directory[/var/log/chef] owner changed to 0
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: directory[/var/log/chef] group changed to 0
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: directory[/var/log/chef] mode changed to 755
 [18.222.176.255] 
 [18.222.176.255]     
 [18.222.176.255] - change mode from '' to '0755'
 [18.222.176.255] 
 [18.222.176.255]     
 [18.222.176.255] - change owner from '' to 'root'
 [18.222.176.255] 
 [18.222.176.255]     
 [18.222.176.255] - change group from '' to 'root'
 [18.222.176.255] 
 [18.222.176.255]   
 [18.222.176.255] * directory[/etc/chef] action create
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: Processing directory[/etc/chef] action create (chef-client::systemd_service line 241)
 [18.222.176.255]  (up to date)
 [18.222.176.255] 
 [18.222.176.255]   
 [18.222.176.255] * template[/etc/default/chef-client] action create
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: Processing template[/etc/default/chef-client] action create (chef-client::systemd_service line 28)
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: template[/etc/default/chef-client] created file /etc/default/chef-client
 [18.222.176.255] 
 [18.222.176.255]     
 [18.222.176.255] - create new file /etc/default/chef-client
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: template[/etc/default/chef-client] updated file contents /etc/default/chef-client
 [18.222.176.255] 
 [18.222.176.255]     
 [18.222.176.255] - update content in file /etc/default/chef-client from none to 583fc4
 [18.222.176.255] 
 [18.222.176.255]     
 [18.222.176.255] --- /etc/default/chef-client	2020-11-06 07:31:18.638227886 +0000
 [18.222.176.255] 
 [18.222.176.255]     
 [18.222.176.255] +++ /etc/default/.chef-chef-client20201106-1740-12ikjh3	2020-11-06 07:31:18.638227886 +0000
 [18.222.176.255] 
 [18.222.176.255]     
 [18.222.176.255] @@ -1 +1,5 @@
 [18.222.176.255] 
 [18.222.176.255]     
 [18.222.176.255] +CONFIG=/etc/chef/client.rb
 [18.222.176.255] 
 [18.222.176.255]     
 [18.222.176.255] +INTERVAL=1800
 [18.222.176.255] 
 [18.222.176.255]     
 [18.222.176.255] +SPLAY=300
 [18.222.176.255] 
 [18.222.176.255]     
 [18.222.176.255] +OPTIONS=""
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: template[/etc/default/chef-client] mode changed to 644
 [18.222.176.255] 
 [18.222.176.255]     
 [18.222.176.255] - change mode from '' to '0644'
 [18.222.176.255] 
 [18.222.176.255]   
 [18.222.176.255] * directory[/etc/systemd/system] action create
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: Processing directory[/etc/systemd/system] action create (chef-client::systemd_service line 34)
 [18.222.176.255]  (up to date)
 [18.222.176.255] 
 [18.222.176.255]   
 [18.222.176.255] * systemd_unit[chef-client.service] action create
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: Processing systemd_unit[chef-client.service] action create (chef-client::systemd_service line 73)
 [18.222.176.255] 
 [18.222.176.255]     
 [18.222.176.255] * file[/etc/systemd/system/chef-client.service] action create
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: Processing file[/etc/systemd/system/chef-client.service] action create (/opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.6.14/lib/chef/provider/systemd_unit.rb line 234)
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: file[/etc/systemd/system/chef-client.service] created file /etc/systemd/system/chef-client.service

      - create new file /etc/systemd/system/chef-client.service[2020-11-06T07:31:18+00:00] INFO: file[/etc/systemd/system/chef-client.service] updated file contents /etc/systemd/system/chef-client.service

      - update content in file /etc/systemd/system/chef-client.service from none to 334f35
      --- /etc/systemd/system/chef-client.service	2020-11-06 07:31:18.882221948 +0000
      +++ /etc/systemd/system/.chef-chef-client20201106-1740-robno5.service	2020-11-06 07:31:18.806223798 +0000
      @@ -1 +1,15 @@
      +[Unit]
      +Description = Chef Infra Client daemon
      +After = network.target auditd.service
      +
      +[Service]
      +Type = simple
      +EnvironmentFile = /etc/default/chef-client
      +ExecStart = /opt/chef/bin/chef-client -c $CONFIG -i $INTERVAL -s $SPLAY $OPTIONS
      +ExecReload = /bin/kill -HUP $MAINPID
      +SuccessExitStatus = 3
      +Restart = always
      +
      +[Install]
 [18.222.176.255] 
 [18.222.176.255]       
 [18.222.176.255] +WantedBy = multi-user.target
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: file[/etc/systemd/system/chef-client.service] owner changed to 0
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: file[/etc/systemd/system/chef-client.service] group changed to 0
 [18.222.176.255] [2020-11-06T07:31:18+00:00] INFO: file[/etc/systemd/system/chef-client.service] mode changed to 644
 [18.222.176.255] 
 [18.222.176.255]       
 [18.222.176.255] - change mode from '' to '0644'
 [18.222.176.255] 
 [18.222.176.255]       
 [18.222.176.255] - change owner from '' to 'root'
 [18.222.176.255] 
 [18.222.176.255]       
 [18.222.176.255] - change group from '' to 'root'
 [18.222.176.255] 
 [18.222.176.255]     - creating unit: chef-client.service
[2020-11-06T07:31:19+00:00] INFO: systemd_unit[chef-client.service] not queuing delayed action restart on service[chef-client] (delayed), as it's already been queued
  * systemd_unit[chef-client.timer] action stop[2020-11-06T07:31:19+00:00] INFO: Processing systemd_unit[chef-client.timer] action stop (chef-client::systemd_service line 79)
 [18.222.176.255]  (up to date)
  * systemd_unit[chef-client.timer] action disable[2020-11-06T07:31:19+00:00] INFO: Processing systemd_unit[chef-client.timer] action disable (chef-client::systemd_service line 79)
 [18.222.176.255]  (up to date)
  * systemd_unit[chef-client.timer] action delete[2020-11-06T07:31:19+00:00] INFO: Processing systemd_unit[chef-client.timer] action delete (chef-client::systemd_service line 79)
 [18.222.176.255]  (up to date)
  * service[chef-client] action enable[2020-11-06T07:31:19+00:00] INFO: Processing service[chef-client] action enable (chef-client::systemd_service line 93)
 [18.222.176.255] [2020-11-06T07:31:19+00:00] INFO: service[chef-client] enabled

    - enable service service[chef-client]
  * service[chef-client] action start[2020-11-06T07:31:19+00:00] INFO: Processing service[chef-client] action start (chef-client::systemd_service line 93)
 [18.222.176.255] [2020-11-06T07:31:20+00:00] INFO: service[chef-client] started

    - start service service[chef-client]
[2020-11-06T07:31:20+00:00] INFO: template[/etc/default/chef-client] sending restart action to service[chef-client] (delayed)
  * service[chef-client] action restart[2020-11-06T07:31:20+00:00] INFO: Processing service[chef-client] action restart (chef-client::systemd_service line 93)
 [18.222.176.255] [2020-11-06T07:31:20+00:00] INFO: service[chef-client] restarted

    - restart service service[chef-client]
[2020-11-06T07:31:20+00:00] DEBUG: Saving the current state of node ddubey-ubu-msys-audit
 [18.222.176.255] [2020-11-06T07:31:20+00:00] INFO: Chef Infra Client Run complete in 3.059166491 seconds
 [18.222.176.255] 
 [18.222.176.255] Running handlers:
 [18.222.176.255] 
 [18.222.176.255] [2020-11-06T07:31:20+00:00] INFO: Running report handlers
 [18.222.176.255] [2020-11-06T07:31:21+00:00] DEBUG: Reporter is [json-automate]
 [18.222.176.255] [2020-11-06T07:31:21+00:00] INFO: Using InSpec 4.23.11
 [18.222.176.255] [2020-11-06T07:31:21+00:00] DEBUG: Options are set to: {"report"=>true, "format"=>"json-automate", "reporter"=>["json-automate"], "output"=>"/dev/null", "logger"=>Chef::Log, :backend_cache=>true, :attributes=>{}, :waiver_file=>[], :reporter_message_truncation=>10000, :reporter_backtrace_inclusion=>false}
 [18.222.176.255] [2020-11-06T07:31:21+00:00] ERROR: InSpec has raised a runtime exception. Generating a minimal failed report.
[2020-11-06T07:31:21+00:00] ERROR: No audit tests are defined

Please revert with steps that I can use to reproduce.

@collinmcneese
Copy link
Contributor

So things work fine if you run chef-client interactively, because that has the HOME env var set. The problem is when chef-client is running as a service/daemon, then you'll see the errors.

On my config, I have the interval set down to 30 seconds so that i can get a faster feedback loop then the error appears when tailing the message log (and when sending results in to Automate as @srb3 posted)

@collinmcneese
Copy link
Contributor

This is definitely a HOME expansion-related issue -- if i add ENV['HOME'] = '/etc/chef' to my client.rb (or in my case added it to /etc/chef/client.d/env.rb since I'm using the chef-client cookbook) the error goes away when running as a service as well

@kvivek1115 kvivek1115 self-assigned this Nov 12, 2020
@mattray
Copy link
Contributor

mattray commented Nov 18, 2020

FYI it also affects any knife calls from within an execute resource

This was referenced Nov 27, 2020
Closed
Merged
@kvivek1115
Copy link
Contributor

The issue somehow related to pry/pry#2139

@kvivek1115 kvivek1115 mentioned this issue Dec 1, 2020
Closed
@kvivek1115
Copy link
Contributor

@tas50 & @lamont-granquist, As per my investigation seems the regression due to pry version 13.1 updated in inspec inspec/inspec#4992, it already reported at pry/pry#2139.

Is it feasible to set the HOME path? if missing by fetching it using Etc.getpwuid(Process.uid).dir?

I have tried to track down the File.expand_path here pry/pry#2165. But it gets worse and a couple more library required fixes ie. readline lib raising the exception if HOME is not set.

Here the chef-client logs after Pry fixes:

ERROR: Report handler Chef::Handler::AuditReport raised #<RuntimeError: HOME environment variable (or HOMEDRIVE and HOMEPATH) must be set and point to a directory>
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/rb-readline-0.5.5/lib/rbreadline.rb:1097:in `<module:RbReadline>'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/rb-readline-0.5.5/lib/rbreadline.rb:17:in `<top (required)>'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/rb-readline-0.5.5/lib/readline.rb:10:in `<module:Readline>'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/rb-readline-0.5.5/lib/readline.rb:8:in `<top (required)>'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/byebug-11.1.3/lib/byebug/history.rb:4:in `<top (required)>'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/byebug-11.1.3/lib/byebug/interface.rb:4:in `require_relative'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/byebug-11.1.3/lib/byebug/interface.rb:4:in `<top (required)>'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/byebug-11.1.3/lib/byebug/core.rb:7:in `require_relative'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/byebug-11.1.3/lib/byebug/core.rb:7:in `<top (required)>'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-byebug-3.9.0/lib/byebug/processors/pry_processor.rb:3:in `<top (required)>'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-byebug-3.9.0/lib/pry-byebug/pry_ext.rb:3:in `<top (required)>'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-byebug-3.9.0/lib/pry-byebug/cli.rb:4:in `<top (required)>'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-0.13.1/lib/pry/plugins.rb:55:in `load_cli_options'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-0.13.1/lib/pry/cli.rb:40:in `each'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-0.13.1/lib/pry/cli.rb:40:in `add_plugin_options'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-0.13.1/lib/pry/cli.rb:134:in `<top (required)>'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/pry-0.13.1/lib/pry.rb:78:in `<top (required)>'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/inspec-core-4.23.11/lib/inspec/shell.rb:2:in `<top (required)>'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/inspec-core-4.23.11/lib/inspec.rb:13:in `<top (required)>'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /home/ad.msystechnologies.com/vivek.singh/.chef/cache/cookbooks/audit/files/default/handler/audit_report.rb:121:in `load_needed_dependencies'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /home/ad.msystechnologies.com/vivek.singh/.chef/cache/cookbooks/audit/files/default/handler/audit_report.rb:56:in `report'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.6.14/lib/chef/handler.rb:258:in `run_report_unsafe'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /home/ad.msystechnologies.com/vivek.singh/.chef/cache/cookbooks/audit/files/default/handler/audit_report.rb:100:in `run_report_safely'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.6.14/lib/chef/handler.rb:123:in `block in run_report_handlers'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.6.14/lib/chef/handler.rb:121:in `each'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.6.14/lib/chef/handler.rb:121:in `run_report_handlers'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.6.14/lib/chef/handler.rb:133:in `block in <class:Handler>'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.6.14/lib/chef/client.rb:423:in `block in run_completed_successfully'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.6.14/lib/chef/client.rb:422:in `each'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.6.14/lib/chef/client.rb:422:in `run_completed_successfully'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.6.14/lib/chef/client.rb:287:in `run'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.6.14/lib/chef/application.rb:323:in `block in fork_chef_client'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.6.14/lib/chef/application.rb:311:in `fork'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.6.14/lib/chef/application.rb:311:in `fork_chef_client'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.6.14/lib/chef/application.rb:276:in `block in run_chef_client'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.6.14/lib/chef/local_mode.rb:42:in `with_server_connectivity'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.6.14/lib/chef/application.rb:264:in `run_chef_client'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.6.14/lib/chef/application/base.rb:403:in `sleep_then_run_chef_client'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.6.14/lib/chef/application/base.rb:392:in `block in interval_run_chef_client'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.6.14/lib/chef/application/base.rb:391:in `loop'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.6.14/lib/chef/application/base.rb:391:in `interval_run_chef_client'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.6.14/lib/chef/application/base.rb:344:in `run_application'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-16.6.14/lib/chef/application.rb:67:in `run'
Dec  1 14:33:26 node1 chef-client[2232]: [2020-12-01T14:33:26+00:00] ERROR: /opt/chef/embedded/lib/ruby/gems/2.7.0/gems/chef-bin-16.6.14/bin/chef-client:25:in `<top (required)>'

@kvivek1115
Copy link
Contributor

The issue got fixed with the latest version of inspec, have tested it with chef 16.8.14, it seems working fine.

Dec 17 09:04:20 vagrant systemd[1]: Starting Hostname Service...
Dec 17 09:04:20 vagrant dbus[846]: [system] Successfully activated service 'org.freedesktop.hostname1'
Dec 17 09:04:20 vagrant systemd[1]: Started Hostname Service.
Dec 17 09:04:20 vagrant chef-client[2358]: resolving cookbooks for run list: ["viv_chef_client", "viv-audit"]
Dec 17 09:04:20 vagrant chef-client[2358]: Synchronizing Cookbooks:
Dec 17 09:04:20 vagrant chef-client[2358]:   - viv_chef_client (1.2.28)
Dec 17 09:04:20 vagrant chef-client[2358]:   - chef-client (12.3.3)
Dec 17 09:04:20 vagrant chef-client[2358]:   - logrotate (2.2.3)
Dec 17 09:04:20 vagrant chef-client[2358]:   - audit (9.5.0)
Dec 17 09:04:20 vagrant chef-client[2358]:   - cron (6.3.1)
Dec 17 09:04:20 vagrant chef-client[2358]:   - viv-audit (0.3.1)
Dec 17 09:04:20 vagrant chef-client[2358]: Installing Cookbook Gems:
Dec 17 09:04:20 vagrant chef-client[2358]: Compiling Cookbooks...
Dec 17 09:04:20 vagrant chef-client[2358]: Recipe: audit::inspec
Dec 17 09:04:20 vagrant chef-client[2358]:   * inspec_gem[inspec] action install (up to date)
Dec 17 09:04:20 vagrant chef-client[2358]:   Converging 10 resources
Dec 17 09:04:20 vagrant chef-client[2358]: Recipe: chef-client::systemd_service
Dec 17 09:04:20 vagrant chef-client[2358]:   * directory[/var/run/chef] action create (up to date)
Dec 17 09:04:20 vagrant chef-client[2358]:   * directory[/var/lib/chef] action create (up to date)
Dec 17 09:04:20 vagrant chef-client[2358]:   * directory[/var/log/chef] action create (up to date)
Dec 17 09:04:20 vagrant chef-client[2358]:   * directory[/etc/chef] action create (up to date)
Dec 17 09:04:20 vagrant chef-client[2358]:   * template[/etc/default/chef-client] action create (up to date)
Dec 17 09:04:20 vagrant chef-client[2358]:   * directory[/etc/systemd/system] action create (up to date)
Dec 17 09:04:21 vagrant chef-client[2358]:   * systemd_unit[chef-client.service] action create (up to date)
Dec 17 09:04:21 vagrant chef-client[2358]:   * systemd_unit[chef-client.timer] action stop (up to date)
Dec 17 09:04:21 vagrant chef-client[2358]:   * systemd_unit[chef-client.timer] action disable (up to date)
Dec 17 09:04:21 vagrant chef-client[2358]:   * systemd_unit[chef-client.timer] action delete (up to date)
Dec 17 09:04:21 vagrant chef-client[2358]:   * service[chef-client] action enable (up to date)
Dec 17 09:04:21 vagrant chef-client[2358]:   * service[chef-client] action start (up to date)
Dec 17 09:04:21 vagrant chef-client[2358]: Recipe: audit::inspec
Dec 17 09:04:21 vagrant chef-client[2358]:   * inspec_gem[inspec] action nothing (skipped due to action :nothing)
Dec 17 09:04:21 vagrant chef-client[2358]: Running handlers:
Dec 17 09:04:23 vagrant chef-client[2358]: [2020-12-17T09:04:23+00:00] WARN: DEPRECATION: InSpec Attributes are being renamed to InSpec Inputs to avoid confusion with Chef Attributes. Use :inputs in your kitchen.yml verifier config instead of :attributes.
Dec 17 09:04:24 vagrant chef-client[2358]:   - Chef::Handler::AuditReport
Dec 17 09:04:24 vagrant chef-client[2358]: Running handlers complete
Dec 17 09:04:24 vagrant chef-client[2358]: Chef Infra Client finished, 0/14 resources updated in 05 seconds
Dec 17 09:04:26 vagrant chef-client[2358]: [2020-12-17T09:04:26+00:00] WARN: audit cookbook config values 'attributes_save', 'chef_node_attribute_enabled', 'fail_if_not_present', 'inspec_gem_source', 'inspec_version', 'interval', 'owner', 'raise_if_unreachable' are not supported in Chef Infra Client's Compliance Phase.
Dec 17 09:17:01 vagrant CRON[3119]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@dheerajd-msys dheerajd-msys

@kvivek1115 kvivek1115

Labels
Status: Untriaged An issue that has yet to be triaged.
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
6 participants
@mattray @lamont-granquist @collinmcneese @dheerajd-msys @srb3 @kvivek1115