I wanted to bisect the sources, but "python pkgdb2client/cli.py" command does not work for me. It loads the module from system. After uninstalling packagedb-cli package, it fails like this:

$ python pkgdb2client/cli.py 
Traceback (most recent call last):
  File "pkgdb2client/cli.py", line 26, in <module>
    from pkgdb2client import PkgDB, PkgDBException, __version__
ImportError: No module named pkgdb2client

It tries to open pkgdb2client/pkgdb2client.py. I have not experience with Python, but various web search signals one would have to edit pkgdb2client/__init__.py. How do you run the code from the git tree?

I most often run pkgdb-cli in a virtual environment, but it might be easy to get it working using

$ PYTHONPATH=. python pkgdb2client/cli.py

(Should fix the ImportError you reported above)

I've had a similar report when trying to retire a package, so I've this pretty high on my list, I'm happy to help you bisect it though :)

(In reply to Pierre-YvesChibon from comment #2)
> I most often run pkgdb-cli in a virtual environment,

How do you use it? If I understand it, it creates completely new empty python installation and I will have to install the packagedb-cli including all it's dependencies from upstream there. So it cannot combine dependencies from the system with code from the git. It does not sound like a good way how to identify issues specific to my system.

> but it might be easy to get it working using
> 
> $ PYTHONPATH=. python pkgdb2client/cli.py
> 
> (Should fix the ImportError you reported above)
> 
No, that does not work because it cannot find packagedb-cli:

$ PYTHONPATH=. python pkgdb2client/cli.py
Traceback (most recent call last):
  File "pkgdb2client/cli.py", line 26, in <module>
    from pkgdb2client import PkgDB, PkgDBException, __version__
  File "/home/petr/packagedb-cli/pkgdb2client/__init__.py", line 42, in <module>
    __version__ = pkg_resources.get_distribution('packagedb-cli').version
  File "/usr/lib/python2.7/site-packages/pkg_resources/__init__.py", line 551, in get_distribution
    dist = get_provider(dist)
  File "/usr/lib/python2.7/site-packages/pkg_resources/__init__.py", line 431, in get_provider
    return working_set.find(moduleOrReq) or require(str(moduleOrReq))[0]
  File "/usr/lib/python2.7/site-packages/pkg_resources/__init__.py", line 952, in require
    needed = self.resolve(parse_requirements(requirements))
  File "/usr/lib/python2.7/site-packages/pkg_resources/__init__.py", line 839, in resolve
    raise DistributionNotFound(req, requirers)
pkg_resources.DistributionNotFound: The 'packagedb-cli' distribution was not found and is required by the application

At the end, I installed the git sources using "python setup.py build && python setup.py install --root/tmp/dest" and then run the pkgdb-cli from there using PYTONMODULE pointing there.

But I cannot reproduce the bug today. Maybe there are some differences in the authentication servers.

I've improved the instructions on how to get pkgdb-cli running: https://github.com/fedora-infra/packagedb-cli/pull/78

Ok I've been trying to reproduce this locally.

I might have triggered it once (the first time) but I can't anymore now. Even if I try to use both the current pkgdb-cli from the repo as well as the git version.

I'll wait a little before trying again, maybe it has to do with the time-out of the cookie, not sure.

I bisected it to this commit. This is the first failing commit:

commit 26d4da644be64de8525e07f212c086c9f0741e3d
Author: Ralph Bean <rbean>
Date:   Fri Jan 8 14:23:08 2016 -0500

    Port to openidbaseclient.

I think the cookie is stored in ~/.cache/pkgdb-session.pickle file. I always removed the file before a test.

~/.cache/pkgdb-session.pickle was the location before the commit you're referring to

~/.fedora/openidbaseclient-sessions.cache is the location after that commit

I've been testing w and w/o both, couldn't trigger it :(

If you told me what host names it uses, I would tell you what IP addresses I use. A strace for connect(2) is quite long. These are unique IPv4 addresses in alphabetical order when the login fails:

140.211.169.196
140.211.169.206
152.19.134.142
152.19.134.198
209.132.181.15
209.132.181.16
66.35.62.162
67.203.2.67
67.219.144.68

But because of glibc resolver implementation, not all of them are real connects.

Do you have a reproducer? Like steps when you always trigger the bug?

No. There are time periods (tens of minutes) when it always fails and periods when it always works. Any action requiring authentication, like the command in comment #0, suffers from the problem.

Therefore I believe the new openidbaseclient authentication implementation is not compatible with all Fedora's OpenID servers (there are more of them around the world, I think). The periods could align with caching hosts entries. To verify it, I need to know what host name to look.

Or if the authentication server is busy, it sends the intermediate "operation in progress" answer that openidbaseclient cannot handle. It's the HTTP response code that surprises me. It should be "1xx", but the pkgdb-cli reports "200".

> with all Fedora's OpenID servers (there are more of them around the world, I think)

As far as I know there are only two OpenID servers for Fedora, both load-balanced under id.fedoraproject.org.

Are you in a Red Hat office? I know we've had problem in the past with the networking in Red Hat offices. I am really fishing here, everytime I try to reproduce it, it works for me :/

I encountered the bug again. This time with debuggin prints as advised by Pingou:

FAS password for user ppisar: 
Response {u'response': {u'openid.op_endpoint': u'https://id.fedoraproject.org/openid/', u'openid.sig': u'REMOVED', u'openid.return_to': u'https://admin.fedoraproject.org/pkgdb/_flask_fas_openid_handler/?janrain_nonce=2016-03-17T08%3A57%3A00ZR8PI9x', u'openid.sreg.fullname': u'Petr Pisar', u'openid.ns.cla': u'http://fedoraproject.org/specs/open_id/cla', u'openid.ns': u'http://specs.openid.net/auth/2.0', u'openid.ns.sreg': u'http://openid.net/extensions/sreg/1.1', u'openid.lp.is_member': u'packager', u'openid.mode': u'id_res', u'openid.sreg.nickname': u'ppisar', u'openid.sreg.timezone': u'UTC', u'openid.response_nonce': u'2016-03-17T08:57:02Z6w0LlV', u'openid.signed': u'assoc_handle,cla.signed_cla,claimed_id,identity,lp.is_member,mode,ns,ns.cla,ns.lp,ns.sreg,op_endpoint,response_nonce,return_to,signed,sreg.email,sreg.fullname,sreg.nickname,sreg.timezone', u'openid.cla.signed_cla': u'http://admin.fedoraproject.org/accounts/cla/done', u'openid.assoc_handle': u'{HMAC-SHA1}{REMOVED}{REMOVED}', u'openid.claimed_id': u'http://ppisar.id.fedoraproject.org/', u'openid.ns.lp': u'http://ns.launchpad.net/2007/openid-teams', u'openid.identity': u'http://ppisar.id.fedoraproject.org/', u'openid.sreg.email': u'ppisar'}, u'success': True}
Response <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 3.2 Final//EN">
<title>404 Not Found</title>
<h1>Not Found</h1>
<p>The requested URL was not found on the server.  If you entered the URL manually please check your spelling and try again.</p>

DEBUG:pkgdb-cli:ServerError
ServerError(https://admin.fedoraproject.org/pkgdb/api/package/rpms/perl-Prima/monitor/nobuild, 200, Error returned from json module while processing https://admin.fedoraproject.org/pkgdb/api/package/rpms/perl-Prima/monitor/nobuild: Expecting value: line 2 column 1 (char 1)

<html>
<head>
  <title>OpenID transaction in progress</title>
</head>
etc.

The "Response" messages are from openid_login():

    response = session.post(
        FEDORA_OPENID_API, data=data, verify=not openid_insecure)
    if not bool(response):
        raise ServerError(FEDORA_OPENID_API, response.status_code,
                          'Error returned from our POST to ipsilon.')

    output = response.json()
    print "Response %s" % output

    if not output['success']:
        raise AuthError(output['message'])

    response = session.post(output['response']['openid.return_to'],
                            data=output['response'])
    print "Response %s" % response.text

    return response

It looks like <https://admin.fedoraproject.org/pkgdb/_flask_fas_openid_handler/?janrain_nonce=2016-03-17T08%3A57%3A00ZR8PI9x> handler is not ready when the request with the JSON is sent.

And after removing ~/.fedora/openidbaseclient-sessions.cache it works again.

So I have backed up the offending /.fedora/openidbaseclient-sessions.cache file. 

There are two fedora_ipsilon_session_id and two pkgdb entries. If I keep there at least one of the pkgdb entries, no matter of fedora_ipsilon_session_id entries, it authentication fails.

If I remove both of the pkgdb entries, authentication passes.

I'm suddenly wondering if there would not be some kind of cookie conflict or so.
When you do your testing, do you use another tool in between? Something like the bodhi client or maybe fedpkg?

I'm trying to remember which other app we have who could be using the openid base client from python-fedora, but I can't remember it atm (sorry for being vague), so I thought I could just ask you if you have an idea :)

I do not do testing. I'm trying to use it. Yes, I use bodhi inbetween. I don't think I use fedpkg in any way that requires OpenID authentication.

I think it can be caused by the bodhi client.

Today I removed the ~/.fedora/openidbaseclient-sessions.cache and then used pkgdb-cli. It asked for password and it worked. Then I used bodhi, it asked for password and it worked. The I tried pkgdb-cli again and it worked. After some time (an hour or so) I used bodhi again and it worked. But subsequent attempt to use pkgdb-cli asked for a password and failed with "Not found" message.

The difference in the file content is in the
"https://admin.fedoraproject.org/pkgdb:" value. The working file contains:

[
  ["pkgdb", A],
  ["fedora_ipsilon_session_id", B]
]

The broken file (after the failure) contains:

[
  ["fedora_ipsilon_session_id", B],
  ["pkgdb", A],
  ["pkgdb", C],
  ["fedora_ipsilon_session_id", B]
]

The C string is significantly shorter than A string.

I have bodhi-client-0.9.12.2-3.fc23.

(In reply to Petr Pisar from comment #18)
> I think it can be caused by the bodhi client.
> 
No. I took the working file, tried pkdgb-cli, it failed. I took the working file again, removed the "https://bodhi.fedoraproject.org/:ppisar" subtree, tried pkgdb-cli and it failed either.

Therefore I conclude this does not depend on the bodhi client. Simply the pkgdb-cli is not able complete authentication after expiring the pkgdb session.

A fix for this issue is proposed at https://github.com/fedora-infra/python-fedora/pull/182.

I confirm the patch fixes this issue for me.

python-fedora-0.8.0-1.fc23 has been submitted as an update to Fedora 23. https://bodhi.fedoraproject.org/updates/FEDORA-2016-258acdf02e

python-fedora-0.8.0-1.fc24 has been submitted as an update to Fedora 24. https://bodhi.fedoraproject.org/updates/FEDORA-2016-809a11ce4e

python-fedora-0.8.0-1.fc22 has been submitted as an update to Fedora 22. https://bodhi.fedoraproject.org/updates/FEDORA-2016-c1dfe08924

python-fedora-0.8.0-1.fc24 has been pushed to the Fedora 24 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2016-809a11ce4e

python-fedora-0.8.0-1.fc22 has been pushed to the Fedora 22 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2016-c1dfe08924

python-fedora-0.8.0-1.fc23 has been pushed to the Fedora 23 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2016-258acdf02e

python-fedora-0.8.0-1.fc23 has been pushed to the Fedora 23 stable repository. If problems still persist, please make note of it in this bug report.

python-fedora-0.8.0-1.fc24 has been pushed to the Fedora 24 stable repository. If problems still persist, please make note of it in this bug report.

python-fedora-0.8.0-1.fc22 has been pushed to the Fedora 22 stable repository. If problems still persist, please make note of it in this bug report.