log file unmodified attached

May  5 09:39:45 tsogo1 sogod[50784]: [21717]: [ERROR] <0x0x401439592228[GSCBufferString]> json parser: Expected value while parsing array, attempting once more after unescaping...
May  5 09:39:45 tsogo1 sogod[50784]: [21717]: [ERROR] <0x0x401439592228[GSCBufferString]> total failure. Original string is: e0c^M
May  5 09:39:45 tsogo1 sogod[50784]: {"issuer":"https://auth.test.ec-m.fr/oidc","scopes_supported":["openid","profile","email","address","phone","offline_access","client_configuration_scope","uma_authorization","uma_protection","client_registration_scope"],"response_types_supported":["code","token","id_token","id_token token","device_code"],"response_modes_supported":["query","fragment","form_post"],"subject_types_supported":["public","pairwise"],"claim_types_supported":["normal"],"claims_supported":["sub","acr","name","preferred_username","family_name","given_name","middle_name","profile","picture","nickname","website","zoneinfo","locale","updated_at","birthdate","email","email_verified","phone_number","phone_number_verified","address","gender"],"grant_types_supported":["authorization_code","password","client_credentials","refresh_token","urn:ietf:params:oauth:grant-type:uma-ticket"],"id_token_signing_alg_values_supported":["none","RS256","RS384","RS512","PS256","PS384","PS512","ES256","ES384","ES512","HS256","HS384","HS512"],"dpop_signing_alg_values_supported":["RS256","RS384","RS512","ES256","ES384","ES512"],"id_token_encryption_alg_values_supported":["RSA1_5","RSA-OAEP","RSA-OAEP-256","A128KW","A192KW","A256KW","A128GCMKW","A192GCMKW","A256GCMKW","ECDH-ES","ECDH-ES+A128KW","ECDH-ES+A192KW","ECDH-ES+A256KW"],"id_token_encryption_enc_values_supported":["A128CBC-HS256","A192CBC-HS384","A256CBC-HS512","A128GCM","A192GCM","A256GCM"],"userinfo_signing_alg_values_supported":["none","RS256","RS384","RS512","PS256","PS384","PS512","ES256","ES384","ES512","HS256","HS384","HS512"],"userinfo_encryption_alg_values_supported":["RSA1_5","RSA-OAEP","RSA-OAEP-256","A128KW","A192KW","A256KW","A128GCMKW","A192GCMKW","A256GCMKW","ECDH-ES","ECDH-ES+A128KW","ECDH-ES+A192KW","ECDH-ES+A256KW"],"userinfo_encryption_enc_values_supported":["A128CBC-HS256","A192CBC-HS384","A256CBC-HS512","A128GCM","A192GCM","A256GCM"],"acr_values_supported":["mfa-simple"],"request_object_signing_alg_values_supported":["none","RS256","RS384","RS512","PS256","PS384","PS512","ES256","ES384","ES512","HS256","HS384","HS512"],"request_object_encryption_alg_values_supported":["RSA1_5","RSA-OAEP","RSA-OAEP-256","A128KW","A192KW","A256KW","A128GCMKW","A192GCMKW","A256GCMKW","ECDH-ES","ECDH-ES+A128KW","ECDH-ES+A192KW","ECDH-ES+A256KW"],"request_object_encryption_enc_values_supported":["A128CBC-HS256","A192CBC-HS384","A256CBC-HS512","A128GCM","A192GCM","A256GCM"],"introspection_endpoint_auth_methods_supported":["client_secret_basic"],"token_endpoint_auth_methods_supported":["client_secret_basic","client_secret_post","client_secret_jwt","private_key_jwt"],"code_challenge_methods_supported":["plain","S256"],"prompt_values_supported":["none","login","consent"],"claims_parameter_supported":true,"request_uri_parameter_supported":true,"request_parameter_supported":true,"backchannel_logout_supported":true,"frontchannel_logout_supported":true,"pushed_authorization_request_endpoint":"https://auth.test.ec-m.fr/oidc/oidcPushAuthorize","backchannel_logout_session_supported":true,"frontchannel_logout_session_supported":true,"authorization_endpoint":"https://auth.test.ec-m.fr/oidc/oidcAuthorize","token_endpoint":"https://auth.test.ec-m.fr/oidc/oidcAccessToken","userinfo_endpoint":"https://auth.test.ec-m.fr/oidc/oidcProfile","registration_endpoint":"https://auth.test.ec-m.fr/oidc/register","end_session_endpoint":"https://auth.test.ec-m.fr/oidc/oidcLogout","introspection_endpoint":"https://auth.test.ec-m.fr/oidc/introspect","revocation_endpoint":"https://auth.test.ec-m.fr/oidc/revoke","jwks_uri":"https://auth.test.ec-m.fr/oidc/jwks"}^M
May  5 09:39:45 tsogo1 sogod[50784]: 0^M
May  5 09:39:45 tsogo1 sogod[50784]: ^M
May  5 09:39:45 tsogo1 sogod[50784]: 
May  5 09:39:45 tsogo1 sogod[50784]: [21717:102018] EXCEPTION: <NSException: 0x4014390b11c8> NAME:NSInvalidArgumentException REASON:Tried to add nil value for key 'authorization_endpoint' to dictionary INFO:{}

Hello, found the problem.
Your endpoint use this for the get response
HTTP/1.1 200 200
Transfer-Encoding: chunked
...

This header, deprecated for HTTP/2.0 (https://developer.mozilla.org/en-US/docs/Web/HTTP/Reference/Headers/Transfer-Encoding) is not supported by sogo.

The data received for the endpoint in this transfer mode is:
<size of chunk>
<chunk of data>
<size of chunk>
....
<0>

As sogo don't support this, he thinks that the size of chunk is actual data meaning it will read something like this
e0c
{"issuer"...
Hence the fail of the json parser.

I see that your apereo CAs 6.5.15 has reach end of life (https://apereo.github.io/cas/developer/Maintenance-Policy.html#eol-schedule)
I'm not sure the 7.x.x version doesn't use this header anymore, though. Would you be able to install a fresh apereo cas server with their last version and test it?

Thank you, I'll try, but not very quickly…

Hi

Just FYI I have the same issue with Authentik and Traefik as reverse proxy (both using the latest version):
sogod [3371513]: [ERROR] <0x0x55566c8d1b10[GSCBufferString]> json parser: Expected value while parsing array, attempting once more after unescaping...
sogod [3371513]: [ERROR] <0x0x55566c8d1b10[GSCBufferString]> total failure. Original string is: 75c
...
sogod[3371513:3371513] EXCEPTION: <NSException: 0x55566c8fdf50> NAME:NSInvalidArgumentException REASON:Tried to add nil value for key 'authorization_endpoint' to dictionary INFO:{}

Checking with curl (limiting it to HTTP 1.1) chunking is used:
< Transfer-Encoding: chunked

I suspect there will be many other reverseproxies using this encoding.

Would it be possible for Sogo to use HTTP/2 instead?

Hello,
So for now SOGo uses a internal lib to make request for openid. But I have so much problem with it that I change it for the libcurl (https://curl.se/libcurl/)
I test it with my current keycloak, that was already working, and it seems ok. SOGo also manage to fetch correctly your own server auth.test.ec-m.fr which it couldn't before. Of course I'm stuck just after because my app is not registered.

However, before putting this in the nightly, I want to make a custom package for you to try it and confirm/deny it works better now.
Could you tell me wich repo are you using (OS/version) so I can build a custom package for you ?

I currently use Sogo from the RHEL8 nightly repo (x64). I could test the update.

OK first remove sogo and change the repo url to:
https://packages.sogo.nu/custom/openid_curl/rhel/8
No need to change anything in your sogo.conf

Here we use FreeBSD and locally-compiled packages, I just need source patches to test :)

Hello, this is this branch -> https://github.com/Alinto/sogo/tree/openid_curl no change in SOPE so still master.

I've updated the branch and package to show more logs with the server response
SOGoOpenIDDebugEnabled = YES;
It may give clues if this is still not working.

I just tested: this bug is patched for us (even if oidc login is still not OK, but I have to check the IDP side on this other problem…)

Thank you !

Great, let me know if there is other problems. I'll wait for some other feedback before pushing this into the nightly

Thank you, the OIDC login does work now.

However there seems to be strange behavior at first:
sogod[886797:886797] OpenId perform request: GET https://auth.example.com/application/o/userinfo/
sogod[886797:886797] OpenId perform request, headers {authorization = "Bearer (null)"; "content-type" = "application/x-www-form-urlencoded"; }
sogod[886797:886797] OpenId perform request: response is: <SimpleOpenIdResponse> <status: 401>, <headers: HTTP/1.1 401 Unauthorized

The headers show:
Www-Authenticate: error="invalid_token", error_description="The access token provided is expired, revoked, malformed, or invalid for other reasons"

The issue could be related to the token endpoint which cannot be queried:
sogod[886797:886797] OpenId perform request: POST https://auth.example.com/application/o/token/
sogod[886797:886797] OpenId perform request, headers {"content-type" = "application/x-www-form-urlencoded"; }
sogod[886797:886797] OpenId perform request: response is: <SimpleOpenIdResponse> <status: 400>, <headers: HTTP/1.1 400 Bad Request

Content:
{"error": "invalid_client", "error_description": "Client authentication failed (e.g., unknown client, no client authentication included, or unsupported authentication method)"}

Note: This happens like 4 times in a row, after that the logs show a token being correctly issued and the login succeeding with the correct user info.

Additionally there seems to be an error updating rhe OIDC session table:
sogod [886797]: [ERROR] <0x0x55cc58127d50[GCSOpenIdFolder]> -[GCSOpenIdFolder writeOpenIdSession:withOldSession:withRefreshToken:withExpire:withRefreshExpire:]: cannot write record: <MySQL4Exception: 0x55cc581357a0> NAME:ExecutionFailed REASON:Field 'c_access_token_expires_in' doesn't have a default value
sogod [886797]: [ERROR] <0x0x7f1868242320[SOGoSession]> Value to be secured is too big (2238 > 1575) -- secured value will be corrupted

For the OIDC table see https://bugs.sogo.nu/view.php?id=6122#c18218
I now added a default value to c_access_token_expires_in when creating the table but preexisting table would need to have that manually.

I will take a look for the first point.