Debugging 500 internal error from auth/oauth2/token ?

[10000TB]

I am constantly getting 500 error for password type tokens request against auth/oauth2/token, and trying to figure out what went wrong (no change in auth module at all, and start getting such error), so naturally I start trying adding logging, but could not figure out how, does anyone here know how?

looking at this function from app/modules/auth/views.py

@auth_blueprint.route('/oauth2/token', methods=['GET', 'POST'])
 @oauth2.token_handler
 def access_token(*args, **kwargs):
     # pylint: disable=unused-argument
     """
     This endpoint is for exchanging/refreshing an access token.

     Returns:
         response (dict): a dictionary or None as the extra credentials for
         creating the token response.
     """
     # log.info(**kwargs) # added this, but not seeing anything
     return None

the only logging does not seem to print anything in console.

Can anyone kindly offer anything I can try to debug further ?

[frol]

@10000TB log.info expects the first parameter to be a formatting string, so use log.info("ACCESS TOKEN: args=%r, kwargs=%r", args, kwargs).

[frol]

Is there a traceback in the terminal or in the HTTP/500 response itself (use browser inspector "network" tab)?

Can you run the server in debug mode? (It is the default, but you might have disabled DEBUG in your local_config.py or config.py)

[10000TB]

I tried in debug mode, and looked around the places you mentioned, but sadly, could get an end debug info, I feel the auth token request is worth more logging.

Details:
I was checking both places, no - In console, I simply see transaction records like following:

revproxy_1  | 172.18.0.1 - - [05/Feb/2019:01:14:39 +0000] "GET /auth/oauth2/token?grant_type=password&client_id=documentation&[email protected]&password=whut2eat HTTP/1.1" 500 291 "-" "curl/7.54.0" "-"
api_1       | [pid: 1|app: 0|req: 25/25] 172.18.0.1 () {34 vars in 545 bytes} [Tue Feb  5 01:14:39 2019] GET /auth/oauth2/token?grant_type=password&client_id=documentation&[email protected]&password=whut2eat => generated 291 bytes in 2 msecs (HTTP/1.1 500) 3 headers in 116 bytes (1 switches on core 0)

In browser
It first simply pops up a window say "Authorization failed for unknown reason, please, check your credentials!" (but I know I did enter the right credentials - double checked on it)
At the same time, within browser console, it simply say 500 Internal server error, like this
jquery-1.8.0.min.js:3 POST http://localhost/auth/oauth2/token 500 (INTERNAL SERVER ERROR).
and in network table "XHR", it simply shows a red token record, and 500 error in html and previewed as

Internal Server Error
The server encountered an internal error and was unable to complete your request. Either the server is overloaded or there is an error in the application

[10000TB]

Found the issue accidentally
Later yesterday night, I accidentally found out the issue:

The 500 error happens only in swagger ui, when I check non-continuous oauth scopes ( say in the UI, we have scopes like:
A:read
A:write
B:read
B:write
C:read
C:write
// .. say there are more following
and I checked: A:read A:write and C:read C:write and leave both B scopes unchecked
), it throws that error.
and If I checked continuous scopes, it won't throw the error.

Intermittently, I was seeing some console logs like "auth scopes were invalid", I recall in the error case above, it send auth scopes to server as {'A:read', 'A:write', '', '', 'C:read', 'C:write'}, and looked it set missing/unchecked scope as '' ? which caused the server error - and It was not always logged ? at least from my observation

[frol]

I recall having an issue like that, but I don't remember how and whether I solved it. I will dig into it tomorrow.

[10000TB]

Thanks @frol !

feel free to pass down pointers/clues, and maybe I can take it up

Love to contribute!

[frol]

@10000TB Please, give the fix a try.

It is unfortunate, but I would say that the bug is on Swagger UI 2.x side, it should not add extra spaces between scopes in the scope parameter. There is no point in fixing it in Swagger UI 2.x as they have moved on 3.x. Yet, I cannot upgrade to Swagger UI 3.x due to a few other issues:

• broken OAuth2 support
• The JSON Form Editor is not implemented
• I really find the UX of Swagger UI 3.x broken. I cannot really use it (it looks fine up until the point when you try sending requests, this is where I "fail" to find where is the response) Update Swagger UI to 3.x #56

[10000TB]

I see
Will give it a try !

BTW, did you know what places actually does the “space” part in swagger UI 2.x ? - would it be feasible apply a patch within this project ? (within swagger UI download task, say after we download swagger UI and extract and save it to static folder, then do some pattern search and replace against some .js file to fix the broken function every time)

[frol]

@10000TB I don't know the exact line of code, but I am sure it is easy to track it down (I recall I was already looking into the issue but dropped it as it was not that important for me at that point). However, it would be problematic to apply the patch to the minified version of the JS, which is why I opted to apply a hack on the backend side.

[10000TB]

I see, that make sense

Do you mind sharing clues/hints about where to hack on backend to workaround this issue ?

Where I am confused in terms Of how to hack: it seems to me that scopes values are directly handled by upstream flask-oauthlib in its oauth2.py - and this project’s endpoint (south/token) processing does nothing by delegating the logic via token_handler decorator

[10000TB]

BTW, is the hack you mentioned here related to the fix you mentioned above ?

@10000TB Please, give the fix a try.

It is unfortunate, but I would say that the bug is on Swagger UI 2.x side, it should not add extra spaces between scopes in the scope parameter. There is no point in fixing it in Swagger UI 2.x as they have moved on 3.x. Yet, I cannot upgrade to Swagger UI 3.x due to a few other issues:

• broken OAuth2 support
• The JSON Form Editor is not implemented
• I really find the UX of Swagger UI 3.x broken. I cannot really use it (it looks fine up until the point when you try sending requests, this is where I "fail" to find where is the response) Update Swagger UI to 3.x #56

[frol]

Ah, you seem to miss the commit: 1071254

[10000TB]

Enlightened , 👍

set(scopes) - {''}