Page MenuHomePhabricator
Create Task
Maniphest T142600

Various browser tests failing with MediawikiApi::LoginError
Closed, ResolvedPublic
Actions

Description

Various browser tests are failing due to a login error.

Failing consistently (at least two times in a row, still failing):

Failing intermittently (at least once, but no longer):

selenium-Wikidata failed with MediawikiApi::LoginError in the last test run, but it takes more than 2 hours for the test run, so I am not rerunning it now, will wait until tomorrow.

Track stace looks like:

failed to log in with the returned token '6deec829078b4f823c8af5355cd5becf57aaa61e+\' (MediawikiApi::LoginError)
/mnt/home/jenkins-deploy/.gem/2.0.0/gems/mediawiki_api-0.7.0/lib/mediawiki_api/client.rb:135:in `log_in'
/mnt/home/jenkins-deploy/.gem/2.0.0/gems/mediawiki_api-0.7.0/lib/mediawiki_api/client.rb:136:in `log_in'
/mnt/home/jenkins-deploy/.gem/2.0.0/gems/mediawiki_selenium-1.7.2/lib/mediawiki_selenium/helpers/api_helper.rb:18:in `block in api'
/mnt/home/jenkins-deploy/.gem/2.0.0/gems/mediawiki_selenium-1.7.2/lib/mediawiki_selenium/helpers/api_helper.rb:17:in `tap'
/mnt/home/jenkins-deploy/.gem/2.0.0/gems/mediawiki_selenium-1.7.2/lib/mediawiki_selenium/helpers/api_helper.rb:17:in `api'
/mnt/jenkins-workspace/workspace/selenium-MultimediaViewer/BROWSER/firefox/MEDIAWIKI_ENVIRONMENT/beta/PLATFORM/Linux/label/contintLabsSlave && UbuntuTrusty/tests/browser/features/step_definitions/mmv_steps.rb:4:in `block in <top (required)>'
...

Related Objects

Event Timeline

Restricted Application added a subscriber: Aklapper. · View Herald TranscriptAug 10 2016, 5:26 PM
Jdlrobson added a comment.Aug 10 2016, 8:51 PM

I can replicate this.
x-analytics: "ns=-1;special=Badtitle;WMF-Last-Access=10-Aug-2016;https=1"
x-client-ip: "198.73.209.4"
MediawikiApi::LoginError: failed to log in with the returned token '3d64894be4a585ecf5d8c80dbf31ec8457ab937b+\'
from /Users/jrobson/.rvm/gems/ruby-2.1.1/gems/mediawiki_api-0.7.0/lib/mediawiki_api/client.rb:135:in `log_in'
from /Users/jrobson/.rvm/gems/ruby-2.1.1/gems/mediawiki_api-0.7.0/lib/mediawiki_api/client.rb:136:in `log_in'
from (irb):3
from /Users/jrobson/.rvm/rubies/ruby-2.1.1/bin/irb:11:in `<main>'

IT seems to happen when the user needs to change their password.
I tried for a user with a 6 character password and I got the above message.
When I login I see this screen:

I do not get the same issue with another account which doesn't have the password prompt.

Jdlrobson added a comment.EditedAug 10 2016, 8:52 PM
2.1.1 :001 > require 'mediawiki_api'
 => true 
2.1.1 :002 > c = MediawikiApi::Client.new('https://en.wikipedia.beta.wmflabs.org/w/api.php', true)
 => #<MediawikiApi::Client:0x00000102bf5830 @cookies=#<HTTP::CookieJar:0x00000102bf5808 @store=#<HTTP::CookieJar::HashStore:0x00000102c1fae0 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x00000102c1fa90>, @logger=nil, @gc_threshold=150, @jar={}, @gc_index=0>>, @conn=#<Faraday::Connection:0x00000102c1f900 @parallel_manager=nil, @headers={"User-Agent"=>"Faraday v0.9.2"}, @params={}, @options=#<Faraday::RequestOptions (empty)>, @ssl=#<Faraday::SSLOptions (empty)>, @default_parallel_manager=nil, @builder=#<Faraday::RackBuilder:0x00000102c1f680 @handlers=[Faraday::Request::Multipart, Faraday::Request::UrlEncoded, Faraday::Response::Logger, Faraday::CookieJar, FaradayMiddleware::FollowRedirects, Faraday::Adapter::NetHttp]>, @url_prefix=#<URI::HTTPS:0x00000102c1f3b0 URL:https://en.wikipedia.beta.wmflabs.org/w/api.php>, @proxy=nil>, @logged_in=false, @tokens={}> 
2.1.1 :003 > c.log_in('ShortBadPassword', 'fake')
I, [2016-08-10T13:50:00.998792 #22282]  INFO -- : post https://en.wikipedia.beta.wmflabs.org/w/api.php
D, [2016-08-10T13:50:00.998904 #22282] DEBUG -- request: User-Agent: "Faraday v0.9.2"
Content-Type: "application/x-www-form-urlencoded"

I, [2016-08-10T13:50:04.447329 #22282]  INFO -- Status: 200
D, [2016-08-10T13:50:04.447494 #22282] DEBUG -- response: date: "Wed, 10 Aug 2016 20:50:04 GMT"
content-type: "application/json; charset=utf-8"
content-length: "229"
connection: "close"
server: "deployment-mediawiki01.deployment-prep.eqiad.wmflabs"
x-powered-by: "HHVM/3.12.1"
vary: "Accept-Encoding"
x-frame-options: "SAMEORIGIN"
p3p: "CP=\"This is not a P3P policy! See https://en.wikipedia.beta.wmflabs.org/wiki/Special:CentralAutoLogin/P3P for more info.\""
cache-control: "private, must-revalidate, max-age=0"
x-content-type-options: "nosniff"
set-cookie: "enwikiSession=kgnjibimrodauf63o82eo6idlc134lf6; path=/; secure; httponly, WMF-Last-Access=10-Aug-2016;Path=/;HttpOnly;secure;Expires=Sun, 11 Sep 2016 12:00:00 GMT, GeoIP=US:CA:San_Francisco:37.79:-122.39:v4; Path=/; secure; Domain=.beta.wmflabs.org"
backend-timing: "D=3080584 t=1470862201690582"
x-varnish: "684014097, 1212193766"
via: "1.1 varnish, 1.1 varnish"
accept-ranges: "bytes"
age: "0"
x-cache: "deployment-cache-text04 pass, deployment-cache-text04 pass"
x-cache-status: "pass"
x-analytics: "ns=-1;special=Badtitle;https=1;nocookies=1"
x-client-ip: "198.73.209.4"
I, [2016-08-10T13:50:04.448270 #22282]  INFO -- : post https://en.wikipedia.beta.wmflabs.org/w/api.php
D, [2016-08-10T13:50:04.448367 #22282] DEBUG -- request: User-Agent: "Faraday v0.9.2"
Content-Type: "application/x-www-form-urlencoded"
I, [2016-08-10T13:50:04.877614 #22282]  INFO -- Status: 200
D, [2016-08-10T13:50:04.877877 #22282] DEBUG -- response: date: "Wed, 10 Aug 2016 20:50:05 GMT"
content-type: "application/json; charset=utf-8"
content-length: "229"
connection: "close"
server: "deployment-mediawiki01.deployment-prep.eqiad.wmflabs"
x-powered-by: "HHVM/3.12.1"
vary: "Accept-Encoding"
x-frame-options: "SAMEORIGIN"
p3p: "CP=\"This is not a P3P policy! See https://en.wikipedia.beta.wmflabs.org/wiki/Special:CentralAutoLogin/P3P for more info.\""
cache-control: "private, must-revalidate, max-age=0"
x-content-type-options: "nosniff"
set-cookie: "enwikiSession=07hvh0ktek0fb9dfbgvbifaub7nlg5rj; path=/; secure; httponly"
backend-timing: "D=77570 t=1470862205139394"
x-varnish: "684014135, 1212193774"
via: "1.1 varnish, 1.1 varnish"
accept-ranges: "bytes"
age: "0"
x-cache: "deployment-cache-text04 pass, deployment-cache-text04 pass"
x-cache-status: "pass"
x-analytics: "ns=-1;special=Badtitle;WMF-Last-Access=10-Aug-2016;https=1"
x-client-ip: "198.73.209.4"
MediawikiApi::LoginError: failed to log in with the returned token '3d64894be4a585ecf5d8c80dbf31ec8457ab937b+\'
	from /Users/jrobson/.rvm/gems/ruby-2.1.1/gems/mediawiki_api-0.7.0/lib/mediawiki_api/client.rb:135:in `log_in'
	from /Users/jrobson/.rvm/gems/ruby-2.1.1/gems/mediawiki_api-0.7.0/lib/mediawiki_api/client.rb:136:in `log_in'
	from (irb):3
	from /Users/jrobson/.rvm/rubies/ruby-2.1.1/bin/irb:11:in `<main>'
Tgr added a comment.Aug 10 2016, 9:01 PM

Oh, right, I didn't think of that. The least painful way to fix it is just to change passwords. The old login API just submits the username and password and fails if that's not enough to log you in. Normally the way for bots to log in reliably is to use bot passwords, but that only gives you access to the API, so it's not useful for browser tests.

Jdlrobson added a subscriber: greg.Aug 10 2016, 9:57 PM

@greg is it possible for your team to rule out whether the user that runs the beta cluster tests simply needs a password change?

greg added a comment.Aug 10 2016, 10:04 PM

They can be changed in the jenkins credential store: https://integration.wikimedia.org/ci/credential-store/domain/selenium/

If it is changed there, please change it at https://office.wikimedia.org/wiki/Selenium_passwords as well

I presume it is User:Selenium_user on beta cluster, yes?

greg added a comment.Aug 10 2016, 10:06 PM

I don't see any warning about changing the password when I manually log in to this selenium user account

Jdlrobson added a comment.Aug 10 2016, 11:02 PM

Thanks @greg
Looking closely all issues seem to be in api.create_page

So it might be an issue with the login here:
https://github.com/wikimedia/mediawiki-ruby-api/blob/2f83f589790047c03e0d1e49b66c5b4e5ac98262/lib/mediawiki_api/client.rb#L124

greg added a comment.Aug 10 2016, 11:06 PM

sure, not sure how that changes the test i just did where I can log in using the username/password without prompt for changing it

Tgr added a comment.Aug 11 2016, 12:19 AM
In T142600#2541959, @greg wrote:

I presume it is User:Selenium_user on beta cluster, yes?

No, I tested that in T142141#2538427.

The general solution would be to make it easier to enable verbose logging in mediawiki_api; I'll take a shot at that.

gerritbot added a subscriber: gerritbot.Aug 11 2016, 9:44 PM

Change 304331 had a related patch set uploaded (by Gergő Tisza):
0.7.1: Increase log verbosity

https://gerrit.wikimedia.org/r/304331

gerritbot added a project: Patch-For-Review.Aug 11 2016, 9:44 PM

Change 304332 had a related patch set uploaded (by Gergő Tisza):
1.7.3: Add API log level to environment settings

https://gerrit.wikimedia.org/r/304332

Tgr added a comment.Aug 11 2016, 9:52 PM

@greg I'm not sure how to proceed. The above two patches add detailed logging to the test output which is good for manual testing, but it also includes the password and session cookie so it is only useful for debugging CI problems if we can selectively make the output nonpublic when the logging flag is set. Is that possible?

Also, while this would tell which user is failing, it still doesn't tell why it is falling as the API does not say (or even log) that. That needs to be fixed in MediaWiki core.

gerritbot added a comment.Aug 16 2016, 11:47 PM

Change 305157 had a related patch set uploaded (by Gergő Tisza):
Log failure reasons in ApiLogin

https://gerrit.wikimedia.org/r/305157

gerritbot added a comment.Aug 17 2016, 6:10 PM

Change 305157 merged by jenkins-bot:
Log failure reasons in ApiLogin

https://gerrit.wikimedia.org/r/305157

Tgr added a comment.Aug 18 2016, 12:19 AM

I re-ran the failing test but nothing was logged on beta (see authentication channel). Which in hindsight is not surprising, failed to log in with the returned token is reported when the API returns NeedToken, other error codes have a different message.

I can't reproduce the error in T142600#2541624 either; MediawikiApi::LoginError: Aborted as expected. Jon, can you retry that with https://gerrit.wikimedia.org/r/#/c/304332/ applied?

zeljkofilipin triaged this task as Normal priority.Aug 18 2016, 2:50 PM
zeljkofilipin updated the task description. (Show Details)
zeljkofilipin renamed this task from Various browser tests failing due to login error to Various browser tests failing with MediawikiApi::LoginError.Aug 18 2016, 3:05 PM
gerritbot added a comment.Aug 18 2016, 3:12 PM

Change 305515 had a related patch set uploaded (by Zfilipin):
WIP Fix MediawikiApi::LoginError

https://gerrit.wikimedia.org/r/305515

gerritbot added a comment.Aug 18 2016, 3:19 PM

Change 305515 abandoned by Zfilipin:
WIP Fix MediawikiApi::LoginError

Reason:
Did not help :(

https://integration.wikimedia.org/ci/view/Selenium/job/selenium-QuickSurveys-305515/

https://gerrit.wikimedia.org/r/305515

Jdlrobson raised the priority of this task from Normal to High.Aug 19 2016, 4:02 PM

I've personally started ignoring browser tests which is a bad sign so bumping priority. Does anyone have any theories on what broke this and how we might fix this??

zeljkofilipin claimed this task.Aug 19 2016, 4:06 PM

I am working on this, I have tried a few things, no luck yet.

Stashbot mentioned this in T143655: internal_api_error_LocalFileLockError while uploading file via API to commons.wikimedia.beta.wmflabs.org.Aug 24 2016, 9:50 AM
Stashbot added a subscriber: Stashbot.

Mentioned in SAL [2016-08-24T09:50:33Z] <hashar> deployment-redis02 fixed AOF file /srv/redis/deployment-redis02-6379.aof and restarted the redis instance should fix T143655 and might help T142600

zeljkofilipin added a subscriber: hashar.Aug 24 2016, 12:56 PM

As far as I can see, this is resolved when @hashar fixed redis. I will wait until tomorrow for all selenium jobs to run and then resolve the task if the error is gone.

zeljkofilipin closed this task as Resolved.Aug 25 2016, 9:32 AM

The problem seems to be fixed. I have just checked all selenium jobs, and none of them have failed with MediawikiApi::LoginError.

Jdlrobson added a comment.Aug 25 2016, 5:19 PM

Thank you for fixing this <3.

gerritbot added a comment.May 26 2017, 12:01 PM

Change 304331 abandoned by Zfilipin:
0.7.1: Increase log verbosity

Reason:
mediawiki/ruby/api is in maintenance-only mode

https://gerrit.wikimedia.org/r/304331

gerritbot added a comment.May 26 2017, 12:01 PM

Change 304332 abandoned by Zfilipin:
1.7.3: Add API log level to environment settings

Reason:
mediawiki/selenium is in maintenance-only mode

https://gerrit.wikimedia.org/r/304332

Content licensed under Creative Commons Attribution-ShareAlike 3.0 (CC-BY-SA) unless otherwise noted; code licensed under GNU General Public License (GPL) or other open source licenses. By using this site, you agree to the Terms of Use, Privacy Policy, and Code of Conduct. · Wikimedia Foundation · Privacy Policy · Code of Conduct · Terms of Use · Disclaimer · CC-BY-SA · GPL