pyrax icon indicating copy to clipboard operation
pyrax copied to clipboard

pyrax.set_credentials failure

Open stugots opened this issue 11 years ago • 23 comments

We're using version 1.4.5.

We called pyrax.set_credentials with good credentials. Pyrax decided that we needed to authenticate before we needed to authenticate. :-(

Is this the known swiftclient bug? Or another problem?

Here's the tail end of the stack trace:

Traceback (most recent call last):

[snip]

 File "/usr/local/lib/python2.7/dist-packages/ips_quisitor/common/cloud.py", line 55, in _connection
   pyrax.set_credentials(settings.CF_DS_ACCT, settings.CF_DS_API)

 File "/usr/local/lib/python2.7/dist-packages/pyrax/__init__.py", line 347, in _wrapped
   return fnc(*args, **kwargs)

 File "/usr/local/lib/python2.7/dist-packages/pyrax/__init__.py", line 384, in set_credentials
   _auth_and_connect(region=region)

 File "/usr/local/lib/python2.7/dist-packages/pyrax/__init__.py", line 462, in _auth_and_connect
   connect_to_services(region=region)

 File "/usr/local/lib/python2.7/dist-packages/pyrax/__init__.py", line 515, in connect_to_services
   cloudservers = connect_to_cloudservers(region=region)

 File "/usr/local/lib/python2.7/dist-packages/pyrax/__init__.py", line 347, in _wrapped
   return fnc(*args, **kwargs)

 File "/usr/local/lib/python2.7/dist-packages/pyrax/__init__.py", line 358, in _wrapped
   raise exc.NotAuthenticated(msg)

NotAuthenticated: Authentication required before calling 'connect_to_cloudservers'.

stugots avatar Jun 26 '13 15:06 stugots

I'm leaving for the next two weeks. I don't know when I can look into this, but wanted to let you know that it won't be ignored.

EdLeafe avatar Jun 27 '13 03:06 EdLeafe

Two weeks? I'm envious. :-)

stugots avatar Jun 27 '13 15:06 stugots

Well, it's mostly working and speaking at a conference, so don't be too envious. Then again, it is in Australia, so maybe you can be a little envious. ;-)

EdLeafe avatar Jun 28 '13 01:06 EdLeafe

Just to chime in: In an attempt to workaround my other listed bug (https://github.com/rackspace/pyrax/issues/117) in 1.4.6, I attempted to always do the following in before grabbing the objects that I need (all of which is performed in a loop):

reload(pyrax) 
pyrax.set_credentials(USERNAME, API_KEY)
cfconn = pyrax.connect_to_cloudfiles(region=REGION, public=PUBLIC)
container = cfconn.create_container(CONTAINER)

And started getting the same error that you are mentioning. I am not sure if it is connected with the 401 issues I encountered or not....

mwidman avatar Jul 04 '13 18:07 mwidman

Thanks for supplying another data point!

It happens about once a day for us. I'm ignorantly guessing there's a module on some server that doesn't correctly handle timezones, or passing 12:00 midnight, or something of that nature.

This error has happened to us six times since I opened this ticket.

stugots avatar Jul 04 '13 18:07 stugots

I've just released v1.4.8, which adds workarounds to some of the failures observed in python-swiftclient. Can you please re-test in your environment with that version, and let me know if the problem still remains?

EdLeafe avatar Jul 19 '13 15:07 EdLeafe

will do

stugots avatar Jul 22 '13 18:07 stugots

Will have to wait until #139 is fixed.

stugots avatar Jul 22 '13 21:07 stugots

I'll try version 1.4.9 in our production later this week.

stugots avatar Jul 23 '13 18:07 stugots

The error still happens with pyrax 1.4.9:

screen shot 2013-07-25 at 4 23 42 pm

stugots avatar Jul 25 '13 23:07 stugots

This is sounding more and more like a race condition. Is this being done with threads or multiprocessing? In other words, could more than one connection be trying to authenticate at roughly the same time?

EdLeafe avatar Jul 26 '13 12:07 EdLeafe

It's not being done with threads or multiprocessing.

However, separate processes on different servers could be trying to authenticate at roughly the same time. But these are in completely different address spaces, and are completely separate processes. E.g., Django code running on an apache node, and a Celery background task running on an entirely different server.

stugots avatar Jul 26 '13 14:07 stugots

I don't want to confuse the issue but mine was being used in multithreading. I actually haven't seen the issue for a week or so on 1.4.7 so the exception I was seeing may have been unrelated to this one (although the error was the same).

mwidman avatar Jul 26 '13 16:07 mwidman

Well, I tried running another overnight process last night, and it ran without incident, re-authenticating when the token expired. I'm trying to reproduce the issue, but am not able to. Can you distill what your script is doing into a small sample script that I can run to try to reproduce the issue? I've pretty much tried every combo I can think of, without success. There must be something unique about the order your script is doing things that exposes this issue.

EdLeafe avatar Jul 26 '13 16:07 EdLeafe

I'll try this weekend, and report back.

stugots avatar Jul 26 '13 21:07 stugots

I'm still trying to provoke this bug.

stugots avatar Jul 30 '13 15:07 stugots

This has happened seven times on our production system since 7/24.

7/24: Once 7/25: Four times 7/31: Once 8/1: Once

Each time it happened to an interactive user. There's no try/except in our code at the point where this happens. There should be. I'll add that, and add a credentials request re-try within the except block.

stugots avatar Aug 02 '13 15:08 stugots

Thanks for the update. If possible, could you add debugging/logging to record the token and the expiration time so we can determine if the problem occurs because of a failure to regenerate an expired token, or if there is some other authentication error that is the cause. There have been some scattered issues with configuration in our auth servers recently, so I'd like to make sure what the source of your problem is.

EdLeafe avatar Aug 02 '13 15:08 EdLeafe

We're now running version 1.4.11. This still happens.

I never got around to adding logging, because other tasks reared up to push this down my stack.

Our code calls pyrax.clear_credentials(), then pyrax.set_credentials(). Intermittently, set_credentials fails:

File "/usr/local/lib/python2.7/dist-packages/ips_quisitor/common/cloud.py", line 45, in _connection
   pyrax.set_credentials(settings.CF_DS_ACCT, settings.CF_DS_API)

File "/usr/local/lib/python2.7/dist-packages/pyrax/__init__.py", line 367, in _wrapped
   return fnc(*args, **kwargs)

File "/usr/local/lib/python2.7/dist-packages/pyrax/__init__.py", line 419, in set_credentials
   _auth_and_connect(region=region)

File "/usr/local/lib/python2.7/dist-packages/pyrax/__init__.py", line 493, in _auth_and_connect
   connect_to_services(region=region)

File "/usr/local/lib/python2.7/dist-packages/pyrax/__init__.py", line 557, in connect_to_services
   cloudservers = connect_to_cloudservers(region=region)

File "/usr/local/lib/python2.7/dist-packages/pyrax/__init__.py", line 367, in _wrapped
   return fnc(*args, **kwargs)

File "/usr/local/lib/python2.7/dist-packages/pyrax/__init__.py", line 378, in _wrapped
   raise exc.NotAuthenticated(msg)

NotAuthenticated: Authentication required before calling 'connect_to_cloudservers'.

Since this is entirely in your code, could you shoot me a version with exactly the logging that you need to debug this? I'll install it on our system and can then send you the logs.

stugots avatar Sep 19 '13 17:09 stugots

Wow, this is really spooky - I can't find a possible code path that could result in this traceback. If the _auth_and_connect() call to identity.authenticate() failed, you'd get the auth exception raised there. If it succeeds, identity.authenticated must be True, as that is set at the last line of identity.authenticate(). Nothing in between the two can change that except multiple threads, but we've already ruled that out. So there is no way that the last line of your traceback should ever be reached.

Is it possible to remove your manual re-authentication process, and instead let pyrax handle re-authentication? There really is no good reason to have to do the clear/set_credentials calls that you do, since swiftclient fixed the re-authentication bug we helped to track down.

EdLeafe avatar Sep 20 '13 13:09 EdLeafe

I put in the manual re-authentication because pyrax often failed to do it.

stugots avatar Sep 20 '13 14:09 stugots

Ship me a version with logging, with every statement along the path wrapped in a try/except.

stugots avatar Sep 20 '13 14:09 stugots

I'm running into a different NotAuthenticated exception with pyrax 1.9.7:

 File "/home/bar/virtualenvs/foo/lib/python2.7/site-packages/pyrax/__init__.py", line 739, in connect_to_cloudfiles
   public=is_public)
 File "/home/bar/virtualenvs/foo/lib/python2.7/site-packages/pyrax/__init__.py", line 439, in _wrapped
   return fnc(*args, **kwargs)
 File "/home/bar/virtualenvs/foo/lib/python2.7/site-packages/pyrax/__init__.py", line 450, in _wrapped
   raise exc.NotAuthenticated(msg)
NotAuthenticated: Authentication required before calling '_create_client'.

but this is triggered from django-cumulus so I'll look there first.

thijstriemstra avatar Feb 02 '16 22:02 thijstriemstra