mirror of
https://github.com/advplyr/audiobookshelf.git
synced 2026-05-30 23:40:40 +02:00
[Bug]: Synology SSO "Error in Callback" #1607
Assignees
adam (Adam Melkus)
Clear assignees
adam (Adam Melkus)
No Assignees
Notifications
Due Date
No due date set.
Dependencies
No dependencies set.
Reference: starred/audiobookshelf#1607
Reference in New Issue
Block a user
Delete Branch "%!s()"
Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?
Originally created by @Drakon74 on GitHub (Dec 23, 2023).
Describe the issue
Configured OICD with a Synology SSO Server Endpoint.
Auto discovering the URLs worked just fine.
When trying to log-in, back on the login page, i get an "Error in callback" message.
The log of the container just says:
[2023-12-23 00:13:06.976] ERROR: [Auth] Error in openid callback - OPError: server_error (Auth.js:426)I'm using the "edge" image, with the "latest" image, i get a white page with just "internal server error" and this in the log:
I checked the callback URL, but it is as it should be according to the documentation:
https://[Domain]:5001/auth/openid/callbackThe SSO Server Log just says this though:
User [USER] signed in to application [Audiobookshelf] via SSO.I also already tried to restart the container.
Steps to reproduce the issue
Audiobookshelf version
2.6.0
How are you running audiobookshelf?
Docker
@nichwall commented on GitHub (Dec 23, 2023):
Is this the same issue?
https://github.com/advplyr/audiobookshelf/issues/2412
Most recent commit is https://github.com/advplyr/audiobookshelf/commit/2738402aacbe43f21061667b417da35ceb8d5c10, with the only commits for the last few days being related to adding the Year In Review (assuming the
edgetag was pulled within the past day or two) for future reference@Drakon74 commented on GitHub (Dec 23, 2023):
It sounds like the same issue, however Synology SSO doesn't give me enough "deepthness" so i can check if userinfo_signing_algorithm is on RS265. However the same SSO works just fine with a "gitea" instance.
Also "edge" was pulled basically yesterday.
@Drakon74 commented on GitHub (Dec 23, 2023):
So i did some further digging and testing.
I tried this test here: https://openidconnect.net
And it works fine stating that the token is valid at the end, at the end it also states that the token is signed with RS256. Which, from my understanding, is correct. As the problem in the other issue was that the configuration was wrong in the sense that also the userinfo was signed with RS256.
So i am not entirely sure what i could further do right now...
@Drakon74 commented on GitHub (Dec 23, 2023):
So, i found the reason for the issue... for some reason on the app secret the last character was missing...
I managed to SSH onto the Synology and find the SSO Servers logfile under
/var/packages/SSOServer/target/etc/ssoserver.logWhere it stated this:
So i checked the secret and indeed the last character was missing. No clue how.
However... it is still not working.
i fixed the secret and restarted the container, now i simply get "Unauthorized". The logs on both sides say nothing now. SSO Server Logs just state the successful login now and the audiobookshelf logs mention.. nothing. Only that a socket connected, but nothing more.
The user trying to login already exists on Audiobookstation (same username), could this be an issue? I tried to match the username and e-mail, but it's also not working. Username and e-mail are exactly the same on both sides. Even down to upper / lower case. Am i still missing something?
@Drakon74 commented on GitHub (Dec 24, 2023):
I also updated to 2.7.0 (latest) now and the log at least does mention something now:
[2023-12-24 14:27:54.328] ERROR: [Auth] No data in openid callback - Unauthorized (Auth.js:426)Which sounds like the openid response is empty? But again, it works with gitea and the openid test above. The latter even showing all user information like username, e-mail etc. The SSO Server on the synology is not reporting anything new. Just successful login.
Also i tripple checked everything now, all URLs are correct (i even let it auto-populate again, was no issue), ID and secret are correct, username and e-mail are exactly the same on both sides, callback URL is correct (otherwise the SSO Server complains)...
I have no idea what else i could check or do... i probably miss something still... do i need to put something specific in the reverse proxy settings? Currently there is only the websocket upgrade, as well as the standard like "Host", "X-Forwarded-Proto" and "X-Forwarded-For".
If anyone has an idea, i am open for anything.
@Sapd commented on GitHub (Dec 25, 2023):
Yes, but it is empty because the server (synology) sent back a "Forbidden / 403".
Actually a user in the Discord had the same issue as you (he eventually switched to Authentik). So there must be something special with Synology which we don't know yet about.
Do you have maybe a way to configure the reverse proxy in front of synology to output you detailed http logs?
@Drakon74 commented on GitHub (Dec 25, 2023):
By default it seems only the nginx error log is enabled.
The error log does mention a couple "forbidden", but these are 3 days ago, probably when i was testing and messing around, also they mainly mention the socket connection.
I was able to enable the access log of the nginx however. I censored the log a little, to get the domainname, IPs (public and local) and the client_ID out. But on first glance i cannot see the issue. The snipped is from when i tried to login, so there might be a little bit of other stuff in between as multiple things run on the Synology:
From what i am getting, it seems a proper code and state is returned via the callback URL?
[Client_IP] - - [25/Dec/2023:14:16:43 +0100] "GET /auth/openid/callback?code=fqqgYaeZPLnkMOivnFE1sCHa3O2BSgm8&state=ZNbZrLK0aDQ6zexJKnSraRjMgnxqe9weWK6449Gy9zE HTTP/2.0" 302 128 "https://[DOMAIN]:5001/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.2.1 Safari/605.1.15" "-"@Drakon74 commented on GitHub (Jan 4, 2024):
So i updated to Version 2.7.1 now and tried it again.
This time i get these errors:
Audiobookshelf:
[2024-01-04 22:24:34.607] ERROR: [Auth] Error in openid callback - OPError: server_error (Auth.js:426)Synology SSO Server however gives a new error message:
Jan 4 22:24:34 SSOAccessToken.cpp:line 337 code challenge not passed: method=[S256] challenge=[jXYMFADBPHMOnKkpVwAlWfAMaiReiIMZU0R4cs7G7eg] verifier=[f848pWnCkngcm-4pv-AQuaY0FVMD_67v8oG-8ZltMRU]I checked again, but all links, client ID and secret are the same as before and the same as in the SSO Servers settings.
Any idea what this could be? Would it make sense to perhaps question the Synology Support as well?
@Sapd commented on GitHub (Jan 5, 2024):
Not sure if this error message means, that the PKCE challenge failed or the "code" sent is incorrect.
When inserting here the verifier: https://tonyxu-io.github.io/pkce-generator/
then it returns exactly the challenge from the log message. Which means that PKCE should work.
The library we are using enforces PKCE.
To check if PKCE really works on synology, can you try this in a shell where you have CURL installed?
Before, add
https://oidcdebugger.com/debugas allowed redirect URL in synology.The website will show you a code then. Insert this code in the following variable and run this. Note that you only have a short time for this after you have the code (less than 1-2 minutes)
On success, it should show you a
access_tokenin a JSON@Drakon74 commented on GitHub (Jan 5, 2024):
Yep, seems to work:
Tried it on an external Linux system i have at a hoster.
Used the same client id, secret and links as in the Audiobookshelf config.
(As i am unsure how sensitive the tokens are, i cut them down a little and replaced the rest of them with "..." Hope thats fine, if you need the full tokens, just say a word)
@Sapd commented on GitHub (Jan 5, 2024):
Thats weird. So the issue must somewhere else. Maybe node-openid-client does something weird which specifically bothers synology. Maybe also some URL is weird.
Tbh I think you must configure full logging in front of the synology reverse proxy (headers and full body; and if you dont have a reverse proxy in front of it, you probably must configure one). If you dont have a reverse proxy in front mitmproxy https://docs.mitmproxy.org/stable/ might be easier.
So we can see how the requests from ABS look like and what the response is
Generally you should remove all tokens, they are not needed for understanding the logs.
@Drakon74 commented on GitHub (Jan 6, 2024):
How would you do that in NGINX? I have the built in NGINX setup for both the usually DSM (includes the SSO Server as well) and Audiobookshelf.
My current Log format is like this (i added the request body as well here now):
I separated the logs this time, to make things a bit clearer and it seems with the request body you get more info? Not sure if it is enough though:
Audiobookshelf:
DSM / SSO Server:
EDIT: Also i just noticed, that we're back to just "Unauthorized" the Error i got last time in the SSO Server log is gone now as well... Just mentions login again.
Jan 6 10:27:55 SSOOauth.cpp:line 730 OIDC User[USER] login from AppName[Audiobookshelf]@Sapd commented on GitHub (Jan 6, 2024):
Seems according to the logs authentication worked:
Even the call to userinfo seems to have worked:
Status 200 and it transmitted 99 bytes. So node-openid-client is probably not able to parse the userinfo it gets.
Does the ABS log say now something else?
@Drakon74 commented on GitHub (Jan 6, 2024):
Ah right, sorry, docker logs say this:
[2024-01-06 10:27:55.897] ERROR: [Auth] No data in openid callback - Unauthorized (Auth.js:426)Are there any other logs you can check? In the docker container itself perhaps?
@Sapd commented on GitHub (Jan 6, 2024):
Im not really sure where that "Unauthorized" comes from. Its neither in the node-openid-client code nor in ABS, so it must come from some request. But on the other hand all requests from your logs show status 200 haha.
As far as I can see the logging mechanisms of node-openid-client are not really great.
To debug it further it gets a bit more complicated (at least I dont have a simpler idea)... I think if you want to tackle that you need to run ABS from your computer in VSCode via the debugger and then set a breakpoint at this line:
https://github.com/advplyr/audiobookshelf/blob/a426da534c89a33ff28e6299d690a82ab2fc2081/server/Auth.js#L466
and then follow the calls inside it. A bit similar to the guy here in his screenshots: https://github.com/panva/node-openid-client/issues/275
Then take a look at which line exactly throws that error with what reason.
@Drakon74 commented on GitHub (Jan 6, 2024):
Before i do that, since it would be some effort, do you think it would make sense to ask Synology too?
I mean, i guess they just push it to the application, but maybe they have an idea what it could cause? Their support can be helpful (at times xD)
@Sapd commented on GitHub (Jan 6, 2024):
Well does not hurt to try, maybe some engineer has more information about his implementation. But most companies probably would not look into detail.
@Drakon74 commented on GitHub (Jan 18, 2024):
So i contacted them, and they actually tried to at least investigate some.
They added a own user to both the Synology and Audiobookshelf and tried it themselves, however still getting the same error. They do confirm though that the Synology SSO apparently returns the information.
So i guess i will look into the whole thing with VSCode at some day in the near future xD.
@Sapd commented on GitHub (Jan 19, 2024):
I think it's really cool that they tested it. I would have not expected it tbh, makes a good impression on Synology.
What do you mean by backend? You mean the user is created in ABS?
Edit: With debug logs on, is the message:
"[Auth] openid callback userinfo="displayed in the logs of ABS?@Drakon74 commented on GitHub (Jan 19, 2024):
Yes. They created the user "syno_test" on both sides, Synology and ABS and then tried to login on ABS over SSO, but received the same "Unauthorized" error as before.
How do you enable debug logs?
@Sapd commented on GitHub (Jan 19, 2024):
Ah you didnt do yet. You simply go into ABS admin interface, click on logs. And then on the drop down on the top right you can change the log level.
Try to retest it, could be that there is an important hint.
@Drakon74 commented on GitHub (Jan 19, 2024):
I updated the image to the latest version now too, and enabled debug logs.
Nothing on the synology side. Though according to the log, it does seem to get the data and all?
@Sapd commented on GitHub (Jan 19, 2024):
Ahhh okay, then the error is actually on our side.
It must be a problem somewhere here: https://github.com/advplyr/audiobookshelf/blob/90f4833c9e0957f08799af15966d1909516b335e/server/Auth.js#L98
@advplyr any ideas? The Unauthorized maybe comes from this line: https://github.com/advplyr/audiobookshelf/blob/90f4833c9e0957f08799af15966d1909516b335e/server/Auth.js#L150
@Sapd commented on GitHub (Jan 19, 2024):
@Drakon74
What really weird is, in the userinfo, color information (ANSI control characters) are included:
Basically 32m is the color green, and 39m is the stop color. Can you contact the synology support, and ask if it is intended that there seems that there are color information encoded into the string? Or also if there is a specific encoding required or so.
As far as I can see we are simply outputting the received string, so I don't know where this can come from except possibly form Synology.
@Drakon74 commented on GitHub (Jan 19, 2024):
@Sapd I actually wondered what these would mean as well, good to knows these are the color control characters!
The ticket at Synology was still open, so i relayed the question to them.
@Sapd commented on GitHub (Jan 19, 2024):
So I indeed, on a normal instance (I rechecked) it should output something like:
"[Auth] openid callback userinfo= [object Object]"because the response will be converted to a JSON-object.Instead it cannot do so, because the string received is not valid JSON, giving you the output you have.
@Sapd commented on GitHub (Jan 20, 2024):
@Drakon74 Just to make sure: When you set the log level to debug and you get the same message from above. How does the message look like from the container or application log? (Instead of the log-webinterface in ABS?)
@Drakon74 commented on GitHub (Jan 20, 2024):
This is super weird, i changed nothing, i just set the log level to debug again, and now i am getting "error in callback", despite nothing changed on either side.
The log from yesterday was from the container logs, i think in the web interface it just showed "[Auth] openid callback userinfo= [object Object]" too. Are the logs being written somewhere in the container? I didn't restarted it since yesterday so maybe they're somewhere still.
But yes, now i am getting this: (It's the same between docker and webinterface logs)
I'm really confused slowly xD.
@Drakon74 commented on GitHub (Jan 20, 2024):
Hm nevermind, i reloaded the nginx and now we're back to "Unauthorized" ... super weird.
Anyway, the logs again:
Webinterface:
Docker Logs:
@Sapd commented on GitHub (Jan 20, 2024):
Really weird, something is not consistent in that setup.
Yeah the string is really just coming from outputting the response directly into
console.debug. So the control characters seem to come in fact from Synology, messing up the JSON. Lets wait what the support says.@Drakon74 commented on GitHub (Jan 22, 2024):
So the Synology support responded this:
They also sent me this screenshot, showing they, apparently, went into the Audiobookshelf docker container and ran curl. And i guess no color characters showed up / no color change occurred in the terminal.
@Sapd commented on GitHub (Jan 23, 2024):
Can you do the same again but call curl with the parameter -vvv
@Sapd commented on GitHub (Jan 23, 2024):
Im not sure about your detailed setup. But if your OIDC endpoint is reachable from the Internet, you can send me if you wish the details (i.e. via email, see my GitHub Profile). I can try to debug it on the weekend or so (but no promise on timings)
@Drakon74 commented on GitHub (Jan 28, 2024):
Hey @Sapd,
sorry for the silence. I am sadly rather busy since last week and will still be for about the next 2 weeks. Though i will probably taking you up on that offer of debugging, and no worries about any times! I will contact you via Mail, once i have enough time again.
Still thanks so far!
@nanokatz commented on GitHub (Feb 15, 2024):
Just wanted to add I am having a similar issue but with authentik. Authentik reports succesfull login and as far as i can see ABS gets the info but then ignores it. Unlike the case above though no issue with json conversion.
From the debug logs with info removed:
I am running ABS behind a traefik reverse proxy and this is what the og there shows me:
@Sapd commented on GitHub (Feb 15, 2024):
@nanokatz Best would be to open up a separate issue I think, because its probably not the same (even when Im not 100% sure).
Your error maybe comes from here
Maybe you try to login with an user which is disabled in abs?
@Sapd commented on GitHub (Mar 13, 2024):
To update:
Drakon gave me the OpenID Credentials of his Synology instance, and created an account for me to test logging in.
So I booted up an ABS instance locally, and put in his OpenID credentials.
Funny thing is, for me it works. I can log in via Openid via his Synology instance. Not quite sure currently why it works for me but not for him (using the very same! synology device) - what is different is that it was a new account on his device.
@l3of0x commented on GitHub (Mar 29, 2024):
I am having the same issue, also with Synology. Unfortunately for me creating a new user made no difference. From the logs I see that the JSON coming back to the callback appears to be valid, but still getting the "No data in openid callback" error.
2024/03/28 20:03:00 stderr [2024-03-28 20:03:00.357] ERROR: [Auth] No data in openid callback - Unauthorized (Auth.js:427)
2024/03/28 20:03:00 stdout [2024-03-28 20:03:00.354] DEBUG: [Auth] openid callback userinfo= { email: '', sub: 'testt', username: 'testt' } (Auth.js:101)
2024/03/28 20:00:08 stdout [2024-03-28 20:00:08.045] DEBUG: [Auth] OIDC redirect_uri=https://[redacted]/auth/openid/callback (Auth.js:323)
2024/03/28 19:59:47 stderr [2024-03-28 19:59:47.907] ERROR: [Auth] No data in openid callback - Unauthorized (Auth.js:427)
2024/03/28 19:59:47 stdout [2024-03-28 19:59:47.903] DEBUG: [Auth] openid callback userinfo= { email: '[redacted]', sub: 'john', username: 'john' } (Auth.js:101)
2024/03/28 19:59:38 stdout [2024-03-28 19:59:38.146] DEBUG: [Auth] OIDC redirect_uri=https://[redacted]/auth/openid/callback (Auth.js:323)
I've tried the Match by Username and Match by Email options, the user is active.
I enabled Auto Register, and that created a duplicate user with the same username when I logged in with OIDC, so I guess this is a workaround, but I would like to be able to create users ahead of time and then match on username.
Looking at the SQLite db:
The 2 rows have the same value for username, 2nd row is the autocreated user, and for some reason email was not populated despite being provided in the callback.
@Sapd commented on GitHub (Mar 29, 2024):
@l3of0x What I noticed here is, that
email_verified: true,is missing. Which OIDC must sent with to indicate wether the e-mail is trustworthy. Without it, ABS will simply skip matching by email.Still it does not explain why username matching does not work. It also seems that @Drakon74 is observing the same behaviour.
@Sapd commented on GitHub (Mar 29, 2024):
Oh wait...
preferred_usernameis missing, too. Without that it will also skip matching username.Do you have any options in Synology to set it?
@l3of0x commented on GitHub (Mar 29, 2024):
There are no options in Synology to set the fields that get sent back, but regarding matching as I mentioned when I have Auto Register turned on in ABS after the user is created I am able to log in on subsequent attempts.
Also looking at the code it appears that ABS first tries to match on "sub" which is populated by Synology.
@Sapd commented on GitHub (Mar 29, 2024):
@l3of0x Yeah that is normal. Sub is the main identifier in OpenID which always takes precedence.
Actually
usernameis not defined in the specs, it must bepreferred_usernamewhich synology does not seem to honor.I deployed a fix here if you would like to test: https://github.com/advplyr/audiobookshelf/pull/2769
It also checks for just username and allows email_verified to be null.
@advplyr commented on GitHub (Apr 22, 2024):
Fixed in v2.9.0
@viguice commented on GitHub (Dec 30, 2024):
Do you have been able to enable Synology SSO? The logs of the sso server (/var/packages/SSOServer/target/etc/ssoserver.log) states that the connection is ok:
SSOOauth.cpp:line 730 OIDC User[Cédric] login from AppName[audiobooks]But I get an "Error in callback" message.
I get the following message in the Audiobookshelf logs:
It seems receive an html file when the app is expecting a json file but I don't how to trace what was the initial request that gave the unexpected result.
I tested my current SSO configuration with openidconnect.net and it looks ok. I tried to investigate more using Visual Studio but I didn't figured out how to access remotely the running instance (npm run dev starts on localhost:3333 and is not reachable by my reverse-proxy). I don't know how to bind an internal port to one on my machine as I do usually with docker.
@viguice commented on GitHub (Dec 30, 2024):
FYI, it seems to work after a reboot of my NAS. I don't have a clear understanding why it was not working from the start...