sso-{auth,proxy}: more verbose logging for debugging

[loganmeetsworld]

As pointed out in #125, there are many places where it is hard to debug especially around validation of groups. We should make sure we have thorough logging throughout.

An example around validation: https://github.com/buzzfeed/sso/blob/master/internal/auth/authenticator.go#L805

Also, we've noticed the logging around the redeem flow and transaction is sparse. It'd be great to have a log of where it hits the server and what the state is.

https://github.com/buzzfeed/sso/blob/master/internal/proxy/providers/sso.go#L118

[loganmeetsworld]

Other note: Let's print the configuration settings with all hosts and it's allowed groups on startup. This logic could be cleaned up to error better and log on startup too - https://github.com/buzzfeed/sso/blob/master/internal/auth/options.go#L264

[loganmeetsworld]

See #101 as well

[weeco]

Any update on this, so that I could figure out #125 ?

[loganmeetsworld]

@cotarg is looking into places where logging could be more clear this week and we're hoping to tackle debugging related to #125. We also always welcome community contributions if you know what you'd like to add.

[weeco]

Hey @cotarg any update on this issue? I am still eager to figure out what's causing #125 .

[weeco]

@loganmeetsworld @cotarg Is this being worked on? Please let others know, I consider adding the additional logging myself. Did you hit any roadblocks which stopped you from adding the additional log messages?

[svenmueller]

We are currently having issues getting the group validating working (we followed the existing documentation step by step for setting up service account + domain-wide delegation and enabled ADMIN SDK). The current logged information doesn't really help when looking for the root cause:

{"error":"googleapi: Error 403: Not Authorized to access this resource/api, forbidden","level":"error","msg":"error retrieving groups","service":"sso-authenticator","time":"2019-07-19 09:59:35.7199"}
{"action":"profile","http_status":500,"level":"info","msg":"","proxy_host":"","remote_address":"xxx.xxx.xxx.xxx","request_duration":381.978062,"request_method":"GET","request_uri":"/profile?client_id=<ID>email=email%40domain.com\u0026groups=group%40domain.com","service":"sso-authenticator","time":"2019-07-19 09:59:35.7199","user":"","user_agent":"sso_proxy/HEAD"}

[cameronattard]

+1 for better logging of the group validation process - we are occasionally seeing some flaky behaviour with group validation and have no ability to troubleshoot at the moment.