1343533 - Figure out why tests fail when user_info_class = CGI

Status: NEW

(bugzilla.mozilla.org :: Continous Integration, task, P3)

Description

[David Lawrence [:dkl]]

API Examples:

#   Failed test 'JSON-RPC: Got correct fault for Bug.add_attachment'
#   at lib/QA/RPC.pm line 108.
#     'There is no user account given.'
#         =~
#     'You must log in'

#   Failed test 'JSON-RPC: Got correct fault for Bug.add_attachment'
#   at lib/QA/RPC.pm line 108.
#     'You are not authorized to access bug 5. To see this bug, you must first log in to an account with the appropriate permissions.'
#         =~
#     'You must log in'

#   Failed test 'XML-RPC: Got correct fault for Bug.add_attachment'
#   at lib/QA/RPC.pm line 108.
#     'There is no user account given.'
#         =~
#     'You must log in'

#   Failed test 'XML-RPC: Fault code is set properly'
#   at lib/QA/RPC.pm line 112.
# Code: -32000 Message: There is no user account given.

#   Failed test 'XML-RPC: Got correct fault for Bug.add_attachment'
#   at lib/QA/RPC.pm line 108.
#     'You are not authorized to access bug 5. To see this bug, you must first log in to an account with the appropriate permissions.'
#         =~
#     'You must log in'

Selenium Examples:

#   Failed test 'get_title, 'Log in to Bugzilla''
#   at test_login.t line 25.
#          got: 'Authorization Required'
#     expected: 'Log in to Bugzilla'
# Error requesting http://localhost:4444/selenium-server/driver/:
# ERROR: Element Bugzilla_login not found

#   Failed test 'type, Bugzilla_login, [e-mail]'
#   at test_login.t line 27.
# Error requesting http://localhost:4444/selenium-server/driver/:
# ERROR: Element Bugzilla_password not found

#   Failed test 'type, Bugzilla_password, foo-bar-baz'
#   at test_login.t line 28.
# Error requesting http://localhost:4444/selenium-server/driver/:
# ERROR: Element log_in not found

#   Failed test 'click, log_in'
#   at test_login.t line 29.
# Error requesting http://localhost:4444/selenium-server/driver/:
# Timed out after 60000ms

#   Failed test 'wait_for_page_to_load, 60000'
#   at test_login.t line 30.

#   Failed test 'get_title, 'Invalid Username Or Password''
#   at test_login.t line 31.
#          got: 'Authorization Required'
#     expected: 'Invalid Username Or Password'

#   Failed test 'is_text_present, The username or password you entered is not valid.'
#   at test_login.t line 32.

Comment 1

[Dylan Hardison [:dylan] (he/him)]

Might be related to exceptions. Exceptions work different under cgi than mod perl. Here are the relevant parts of the httpd error log:

[Wed Mar 01 04:07:59 2017] [error] 300: The username or password you entered is not valid. at /var/www/html/bmo/Bugzilla/Auth.pm line 235. \tBugzilla::Auth::_handle_login_result(...) called at /var/www/html/bmo/Bugzilla/Auth.pm line 64 \tBugzilla::Auth::login(...) called at /var/www/html/bmo/Bugzilla.pm line 372 \tBugzilla::login(...) called at /var/www/html/bmo/Bugzilla/WebService/Server.pm line 42 \tBugzilla::WebService::Server::handle_login(...) called at /var/www/html/bmo/Bugzilla/WebService/Server/XMLRPC.pm line 113 \tBugzilla::WebService::Server::XMLRPC::handle_login(...) called at /var/www/html/bmo/xmlrpc.cgi line 41 \tModPerl::ROOT::Bugzilla::ModPerl::ResponseHandler::var_www_html_bmo_xmlrpc_2ecgi::__ANON__(...) called at /var/www/html/bmo/local/lib/perl5/SOAP/Lite.pm line 2760 \tSOAP::Server::find_target(...) called at /var/www/html/bmo/local/lib/perl5/SOAP/Lite.pm line 2877 \teval {...} called at /var/www/html/bmo/local/lib/perl5/SOAP/Lite.pm line 2844 \tSOAP::Server::handle(...) called at /var/www/html/bmo/local/lib/perl5/SOAP/Transport/HTTP.pm line 453 \tSOAP::Transport::HTTP::Server::handle(...) called at /var/www/html/bmo/local/lib/perl5/SOAP/Transport/HTTP.pm line 846 \tSOAP::Transport::HTTP::Apache::handler(...) called at /var/www/html/bmo/xmlrpc.cgi line 42 \tModPerl::ROOT::Bugzilla::ModPerl::ResponseHandler::var_www_html_bmo_xmlrpc_2ecgi::handler(...) called at /usr/lib64/perl5/vendor_perl/ModPerl/RegistryCooker.pm line 204 \teval {...} called at /usr/lib64/perl5/vendor_perl/ModPerl/RegistryCooker.pm line 204 \tModPerl::RegistryCooker::run(...) called at /usr/lib64/perl5/vendor_perl/ModPerl/RegistryCooker.pm line 170 \tModPerl::RegistryCooker::default_handler(...) called at /usr/lib64/perl5/vendor_perl/ModPerl/Registry.pm line 31 \tModPerl::Registry::handler(...) called at /var/www/html/bmo/mod_perl.pl line 139 \tBugzilla::ModPerl::ResponseHandler::handler(...) called at -e line 0 \teval {...} called at -e line 0
[Wed Mar 01 04:08:00 2017] [error] 301: !!This is the text!! If you believe your account should be restored, please send email to [e-mail] explaining why. at /var/www/html/bmo/Bugzilla/Auth.pm line 244. \tBugzilla::Auth::_handle_login_result(...) called at /var/www/html/bmo/Bugzilla/Auth.pm line 80 \tBugzilla::Auth::login(...) called at /var/www/html/bmo/Bugzilla.pm line 372 \tBugzilla::login(...) called at /var/www/html/bmo/Bugzilla/WebService/Server.pm line 42 \tBugzilla::WebService::Server::handle_login(...) called at /var/www/html/bmo/Bugzilla/WebService/Server/XMLRPC.pm line 113 \tBugzilla::WebService::Server::XMLRPC::handle_login(...) called at /var/www/html/bmo/xmlrpc.cgi line 41 \tModPerl::ROOT::Bugzilla::ModPerl::ResponseHandler::var_www_html_bmo_xmlrpc_2ecgi::__ANON__(...) called at /var/www/html/bmo/local/lib/perl5/SOAP/Lite.pm line 2760 \tSOAP::Server::find_target(...) called at /var/www/html/bmo/local/lib/perl5/SOAP/Lite.pm line 2877 \teval {...} called at /var/www/html/bmo/local/lib/perl5/SOAP/Lite.pm line 2844 \tSOAP::Server::handle(...) called at /var/www/html/bmo/local/lib/perl5/SOAP/Transport/HTTP.pm line 453 \tSOAP::Transport::HTTP::Server::handle(...) called at /var/www/html/bmo/local/lib/perl5/SOAP/Transport/HTTP.pm line 846 \tSOAP::Transport::HTTP::Apache::handler(...) called at /var/www/html/bmo/xmlrpc.cgi line 42 \tModPerl::ROOT::Bugzilla::ModPerl::ResponseHandler::var_www_html_bmo_xmlrpc_2ecgi::handler(...) called at /usr/lib64/perl5/vendor_perl/ModPerl/RegistryCooker.pm line 204 \teval {...} called at /usr/lib64/perl5/vendor_perl/ModPerl/RegistryCooker.pm line 204 \tModPerl::RegistryCooker::run(...) called at /usr/lib64/perl5/vendor_perl/ModPerl/RegistryCooker.pm line 170 \tModPerl::RegistryCooker::default_handler(...) called at /usr/lib64/perl5/vendor_perl/ModPerl/Registry.pm line 31 \tModPerl::Registry::handler(...) called at /var/www/html/bmo/mod_perl.pl line 139 \tBugzilla::ModPerl::ResponseHandler::handler(...) called at -e line 0 \teval {...} called at -e line 0

Comment 2

[Dylan Hardison [:dylan] (he/him)]

If generate_bmo_data.pl sets user_info_class to CGI, the following test (and the selenium tests) will fail.
I'm not sure why.

docker run -ti mozillabteam/bmo-ci env TEST_SUITE=webservices runtests.sh

Comment 3

[Dylan Hardison [:dylan] (he/him)]

We're seeing this on dev.

elasticsearch_nodes in the UI is es1.stage.bugs.scl3.mozilla.com:9200
elasticsearch_nodes in the data/params file is es1.stage.bugs.scl3.mozilla.crm:9200 (I intentionally typo'd it)

This suggests Bugzilla->params is staying in memory, which means Bugzilla::clear_request_cache() is not doing
its job -- but only when Persona is not enabled?

Comment 4

[Dylan Hardison [:dylan] (he/him)]

Looking at write_params(), it should be deleting the entry in the request cache.

https://github.com/mozilla-bteam/bmo/blob/master/Bugzilla/Config.pm#L295

but that isn't happening.

I suspect the cleanup handler is not always run, so I'm going to try clearing the request cache before each request.

Comment 5

[Dylan Hardison [:dylan] (he/him)]

This sort of error in production could be quite severe, to the point of people seeing stuff they shouldn't.

Comment 6

[Dylan Hardison [:dylan] (he/him)]

calling clear_request_cache() before each page is effective at stopping this bug, but we should also investigate why _cleanup() fails.

I seem to remember :gozer saying that apache cleanup handlers are synthetic, and possibly not guaranteed to run...
gozer: is that the case here?

Comment 7

[Philippe M. Chiasson (:gozer)]

(In reply to Dylan Hardison [:dylan] from comment #4)
> Looking at write_params(), it should be deleting the entry in the request
> cache.
> 
> https://github.com/mozilla-bteam/bmo/blob/master/Bugzilla/Config.pm#L295
> 
> but that isn't happening.

Well, write_params() deletes the request cache for the current process, but not for other child
processes that might still have a cached version of the param, if I understand the code proprely, no?

> I suspect the cleanup handler is not always run, so I'm going to try
> clearing the request cache before each request.

That's a bit odd, CleanupHandlers will almost always run, they might not complete, see below.

> I seem to remember :gozer saying that apache cleanup handlers are synthetic, and possibly not guaranteed to run...
> gozer: is that the case here?

They are run syntheticely, sort of like an END {} block indeed, after a request terminates, but after the client connection has been closed, thus their usefuleness.

The only caveat is that if that particular child is also shutting down (graceful restart, max request per child, apache::sizelimit, etc) it might get timedout or the underlying child process might die before all code has managed to run. But in the case of a request cache, I don't how that could be a problem, since that child process will not be running new requests during its termination.

Comment 8

[Dylan Hardison [:dylan] (he/him)]

With bug 1307485 backed out, I can't reproduce this error.

Currently comparing dev and staging to see why.

Comment 9

[Dylan Hardison [:dylan] (he/him)]

Correction: This is still happening even without the elastic search code.

Comment 10

[Dylan Hardison [:dylan] (he/him)]

With those fixed, let's turn the setting back and see what happens!

Comment 11

[Dylan Hardison [:dylan] (he/him)]

To github.com:mozilla-bteam/bmo.git
   7a16fee50..7c104643a  master -> master

Comment 12

[Dylan Hardison [:dylan] (he/him)]

Still broken. Good news: it works when GitHubAuth is enabled too.