Chef search query gives 400 bad request

[pkazi]

Description

We are getting intermittent issues on search query which is running from users cookbook , here and here

We are getting 400 bad request and found that query string which is created by chef-client for search is replicated twice in the URL
Example -

users?q=groups:l3support%20AND%20action:remove&start=0&rows=1000?q=groups:l3support%20AND%20action:remove&start=0&rows=1000

users?q=groups:support%20AND%20action:remove&start=0&rows=1000?q=groups:support%20AND%20action:remove&start=0&rows=1000

Logs from chef-server -

/var/log/opscode/opscode-erchef/requests.log.7:2019-09-27T08:39:51Z erchef@127.0.0.1 method=GET; path=/organizations/dev/search/users?q=groups:support%20AND%20action:remove&start=0&rows=1000?q=groups:support%20AND%20action:remove&start=0&rows=1000; status=400; req_id=g3IAA2QAEGVyY2hlZkAxMjcuMC4wLjEBAALWp954AAEAAAAA; org_name=dev; msg={bad_param,{"rows","1000?q=groups:support AND action:remove"}}; couchdb_groups=false; couchdb_organizations=false; couchdb_containers=false; couchdb_acls=false; 503_mode=false; couchdb_associations=false; couchdb_association_requests=false; req_time=3; rdbms_time=0; rdbms_count=1; user=dev1039-20190927-083437; req_api_version=1;

Actual error -

msg={bad_param,{"rows","1000?q=groups:support AND action:remove"}}

Chef Version

Chef: 14.3.37

Platform Version

CentOS Linux release 7.7.1908 (Core)

Linux 3.10.0-1062.1.1.el7.x86_64 chef/chef#1 SMP Fri Sep 13 22:55:44 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux

Replication Case

Able to replicate it when ran search query with 1000 threads from chef-shell

threads = []
1000.times do |x|
        threads << Thread.new do
                sleep [1,2,3,4,5].sample
                max_retries = 5
                p 'Starting' + x.to_s
                users = begin
                    search('users', 'groups:support AND NOT action:remove')
                rescue Net::HTTPServerException => e
                    if e.response.code == '400'
                        retries ||= 0
                        if retries < max_retries
                            retries += 1
                            puts "XXXX  #{x.to_s} 400 bad request - Retrying #{retries/max_retries}"
                            retry
                        else
                            raise e
                        end
                    else
                        raise e
                    end
            end
        end
end
threads.each(&:join)

Client Output

[2019-09-27T07:53:36+00:00] INFO: Processing users_manage[l3support] action remove (base::users line 123)
[2019-09-27T07:53:56+00:00] ERROR: Error connecting to https://chef12-server.com/organizations/dev/search/users?q=groups:l3support%20AND%20action:remove&start=0&rows=1000?q=groups:l3support%20AND%20action:remove&start=0&rows=1000, retry 1/5
[2019-09-27T07:54:01+00:00] INFO: Running queued delayed notifications before re-raising exception
[2019-09-27T07:54:01+00:00] INFO: file[/etc/ssh/ssh_host_dsa_key] sending restart action to service[sshd] (delayed)
[2019-09-27T07:54:01+00:00] INFO: Processing service[sshd] action restart (base::audit line 47)
[2019-09-27T07:54:02+00:00] INFO: service[sshd] restarted
[2019-09-27T07:54:02+00:00] INFO: bash[Reconnect Agent to the manager] sending restart action to service[ossec-hids] (delayed)
[2019-09-27T07:54:02+00:00] INFO: Processing service[ossec-hids] action restart (ossec::common line 83)
[2019-09-27T07:54:04+00:00] INFO: service[ossec-hids] restarted
[2019-09-27T07:54:04+00:00] ERROR: Running exception handlers
[2019-09-27T07:54:05+00:00] INFO: Exported Chef run data to InfluxDB Server
[2019-09-27T07:54:05+00:00] ERROR: Creating Airbrake exception report
[2019-09-27T07:54:06+00:00] ERROR: Exception handlers complete
[2019-09-27T07:54:06+00:00] FATAL: Stacktrace dumped to /var/chef/cache/chef-stacktrace.out
[2019-09-27T07:54:06+00:00

Stacktrace

/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/application.rb:66:in `run'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/bin/chef-client:25:in `<top (required)>'
/bin/chef-client:75:in `load'
/bin/chef-client:75:in `<main>'

>>>> Caused by Net::HTTPServerException: 400 "Bad Request"
/opt/chef/embedded/lib/ruby/2.5.0/net/http/response.rb:122:in `error!'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/http.rb:152:in `request'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/http.rb:115:in `get'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/search/query.rb:160:in `call_rest_service'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/search/query.rb:78:in `search'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/dsl/data_query.rb:39:in `search'
/var/chef/cache/cookbooks/users/resources/manage.rb:166:in `block in class_from_file'
(eval):2:in `block in action_remove'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/provider.rb:236:in `instance_eval'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/provider.rb:236:in `compile_and_converge_action'
(eval):2:in `action_remove'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/provider.rb:182:in `run_action'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/resource.rb:577:in `run_action'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/runner.rb:70:in `run_action'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/runner.rb:98:in `block (2 levels) in converge'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/runner.rb:98:in `each'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/runner.rb:98:in `block in converge'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/resource_collection/resource_list.rb:94:in `block in execute_each_resource'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/resource_collection/stepable_iterator.rb:114:in `call_iterator_block'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/resource_collection/stepable_iterator.rb:85:in `step'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/resource_collection/stepable_iterator.rb:103:in `iterate'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/resource_collection/stepable_iterator.rb:55:in `each_with_index'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/resource_collection/resource_list.rb:92:in `execute_each_resource'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/runner.rb:97:in `converge'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/client.rb:720:in `block in converge'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/client.rb:715:in `catch'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/client.rb:715:in `converge'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/client.rb:754:in `converge_and_save'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/client.rb:286:in `run'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/application.rb:303:in `run_with_graceful_exit_option'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/application.rb:279:in `block in run_chef_client'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/local_mode.rb:44:in `with_server_connectivity'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/application.rb:261:in `run_chef_client'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/application/client.rb:440:in `run_application'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/lib/chef/application.rb:66:in `run'
/opt/chef/embedded/lib/ruby/gems/2.5.0/gems/chef-14.3.37/bin/chef-client:25:in `<top (required)>'
/bin/chef-client:75:in `load'
/bin/chef-client:75:in `<main>'```

[johnmccrae]

Apologies, this got missed. We see that you are on Chef 14 which is unsupported currently. If you can reproduce this on Chef 17, please reopen the ticket.