Closed clmcavaney closed 3 years ago
No that's a new one. You aren't by chance linking in the Google Home app on a phone or tablet that you ALSO have used recently to login to the administrative UI for HomeAutio.Mqtt.GoogleHome? Im unsure where cookies would come in on the oauth handshake, so Im curious if clearing cookies on the device before trying to link makes any difference...
Also, can you give me your full docker command and settings file (redacted) again?
When it (re linking) didn't work on my phone, I did try and login on the browser (which worked fine). I am more than happy to clear the cookies and see. I think the Google Home app used the Chrome browser, so should be easy to test that.
Docker command:
docker run --restart=always --name homeautio.mqtt.googlehome --user=1000 -dit -p 5000:5000 -e ASPNETCORE_PATHBASE="/google/home" \
-e TZ=Australia/Melbourne \
-v /home/chrismc/var/lib/google-home/config:/app/config \
-v /home/chrismc/var/log/google-home:/app/logs \
i8beef/homeautio.mqtt.googlehome:latest
Settings:
{
"deviceConfigFile": "config/googleDevices.json",
"logPII": false,
"mqtt": {
"brokerIp": "mqtt.<local domain>",
"brokerPort": 1883,
"brokerUsername": "googlehome",
"brokerPassword": "**REDACTED**",
"brokerUseTls": false
},
"googleHomeGraph": {
"agentUserId": "115752851588670794851",
"apiKey": "**REDACTED**",
"serviceAccountFile": "config/Google Home MQTT integration-743e95410e7d.json"
},
"oauth": {
"tokenStoreFile": "config/tokens.json",
"authority": "https://googlehome.<my domain>/",
"publicOrigin": "https://googlehome.<my domain>",
"requireSSL": false,
"signingCerts": [
{
"file": "config/signingKey.pfx",
"passPhrase": "**REDACTED**"
}
],
"clients": [
{
"clientId": "845e66ff-**REDACTED**",
"clientSecret": "cadf3dd5-**REDACTED**",
"clientName": "Google Actions Client",
"allowedRedirectUris": [ "https://oauth-redirect.googleusercontent.com/r/home-mqtt-integration" ],
"refreshTokenLifetime": 365
}
],
"resources": [
{
"resourceName": "HomeAutio.Mqtt.GoogleHome"
}
],
"users": [
{
"subjectId": "1ae37d40-7cd4-46e7-8306-241de5d7ba40",
"username": "googleActions",
"password": "**REDACTED**"
}
]
},
"Serilog": {
"Enrich": [ "FromLogContext" ],
"MinimumLevel": "Information",
"WriteTo": [
{ "Name": "Console" },
{
"Name": "RollingFile",
"Args": {
"pathFormat": "logs/HomeAutio.Mqtt.GoogleHome.log",
"retainedFileCountLimit": 31
}
}
]
}
}
Thanks again.
clearing cache and cookies didn't change it - still showing the same error in the logs.
This is very strange as the Docker container had been working with the linking, just the other long standing renewal process failing after a period of idle (i.e. overnight) - that we were looking at in the other issue (see https://github.com/i8beef/HomeAutio.Mqtt.GoogleHome/issues/69)
So, where are the cookies being stored then?
Cookies are only used for the admin interface, not OAuth. .NET would store these inside its cache in the container, which would be lost on container rebuild, but that shouldn't matter, since its basically just session for the admin interface and should be transient anyway.
One other piece, is your proxy correctly setting the X-Forward headers? Everything else LOOKS right besides that (FYI, publicOrigin is no longer needed, IdentityServer4 replaced it with requiting people to properly send X-Forward headers).
code_challenge is missing
I am currently getting the same error.
Will try to check for X-Forward headers. Proxy is Pomerium.
I found something that might be causing this due to an upstream change. I put out a new version. Please try that and see if it fixes your issue.
I was able to reproduce. The upstream IdentityServer OAuth implementation that I updated changed a number of things (without documenting first... docs have caught up a bit now but are still unclear). I seem to have been able to get it to work by reversing a change to the default settings that they made around PKCE, and changing how OAuth scopes are registered. It actually removes the "resources" node of the config file too, so that's nice, but man I wish they had a migration doc together when I chose to do that upgrade.
Try the new version and see if you're good now.
@i8beef I just pulled the new image from docker hub. Now I am getting a different error:
[15:28:21 INF] Writing tokens to config/tokens.json
[15:28:21 INF] Wrote tokens to config/tokens.json
[15:28:21 INF] Request finished in 121.7178ms 200 application/json; charset=UTF-8
[15:28:23 INF] Request starting HTTP/1.1 POST http://home.domain.cc/smarthome application/json;charset=UTF-8 80
[15:28:23 ERR] Exception occurred while processing message.
System.InvalidOperationException: IDX20803: Unable to obtain configuration from: 'https://home.domain.cc/.well-known/openid-configuration'.
at Microsoft.IdentityModel.Protocols.ConfigurationManager`1.GetConfigurationAsync(CancellationToken cancel)
at Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler.HandleAuthenticateAsync()
[15:28:23 ERR] IDX20803: Unable to obtain configuration from: 'https://home.domain.cc/.well-known/openid-configuration'.
System.InvalidOperationException: IDX20803: Unable to obtain configuration from: 'https://home.domain.cc/.well-known/openid-configuration'.
at Microsoft.IdentityModel.Protocols.ConfigurationManager`1.GetConfigurationAsync(CancellationToken cancel)
at Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler.HandleAuthenticateAsync()
at Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler.HandleAuthenticateAsync()
at Microsoft.AspNetCore.Authentication.AuthenticationHandler`1.AuthenticateAsync()
at Microsoft.AspNetCore.Authentication.AuthenticationService.AuthenticateAsync(HttpContext context, String scheme)
at IdentityServer4.AccessTokenValidation.IdentityServerAuthenticationHandler.HandleAuthenticateAsync()
[15:28:23 INF] Bearer was not authenticated. Failure message: IDX20803: Unable to obtain configuration from: 'https://home.domain.cc/.well-known/openid-configuration'.
[15:28:23 INF] Authorization failed.
[15:28:23 INF] AuthenticationScheme: BearerIdentityServerAuthenticationJwt was challenged.
[15:28:23 INF] AuthenticationScheme: Bearer was challenged.
[15:28:23 INF] Request finished in 15.2052ms 401
[15:28:41 INF] Removing expired grants
But if I open https://home.domain.cc/.well-known/openid-configuration
in my browser, I get a response! (also in incognito)
{"issuer":"https://home.domain.cc","jwks_uri":"http://home.domain.cc/.well-known/openid-configuration/jwks","authorization_endpoint":"http://home.domain.cc/connect/authorize","token_endpoint":"http://home.domain.cc/connect/token","userinfo_endpoint":"http://home.domain.cc/connect/userinfo","end_session_endpoint":"http://home.domain.cc/connect/endsession","check_session_iframe":"http://home.domain.cc/connect/checksession","revocation_endpoint":"http://home.domain.cc/connect/revocation","introspection_endpoint":"http://home.domain.cc/connect/introspect","device_authorization_endpoint":"http://home.domain.cc/connect/deviceauthorization","frontchannel_logout_supported":true,"frontchannel_logout_session_supported":true,"backchannel_logout_supported":true,"backchannel_logout_session_supported":true,"scopes_supported":["openid","profile","email","api","offline_access"],"claims_supported":["sub","name","family_name","given_name","middle_name","nickname","preferred_username","profile","picture","website","gender","birthdate","zoneinfo","locale","updated_at","email","email_verified"],"grant_types_supported":["authorization_code","client_credentials","refresh_token","implicit","password","urn:ietf:params:oauth:grant-type:device_code"],"response_types_supported":["code","token","id_token","id_token token","code id_token","code token","code id_token token"],"response_modes_supported":["form_post","query","fragment"],"token_endpoint_auth_methods_supported":["client_secret_basic","client_secret_post"],"id_token_signing_alg_values_supported":["RS256"],"subject_types_supported":["public"],"code_challenge_methods_supported":["plain","S256"],"request_parameter_supported":true}
Hope this helps! best regards
That looks like something not setup correctly with ssl. Your Discovery doc has a mix of http and https urls. It should be all https. What is your oauth.authority set to?
Also make sure you are sending those X-Forward headers. That can cause these issues too.
I update the container and this is what happened near the end of the linking process:
[20:47:47 INF] Request starting HTTP/1.1 POST http://localhost:5000/smarthome application/json;charset=UTF-8 79
[20:47:47 INF] Failed to validate the token.
Microsoft.IdentityModel.Tokens.SecurityTokenInvalidAudienceException: IDX10214: Audience validation failed. Audiences: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]'. Did not match: validationParameters.ValidAudience: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]' or validationParameters.ValidAudiences: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]'.
at Microsoft.IdentityModel.Tokens.Validators.ValidateAudience(IEnumerable`1 audiences, SecurityToken securityToken, TokenValidationParameters validationParameters)
at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateAudience(IEnumerable`1 audiences, JwtSecurityToken jwtToken, TokenValidationParameters validationParameters)
at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateTokenPayload(JwtSecurityToken jwtToken, TokenValidationParameters validationParameters)
at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateToken(String token, TokenValidationParameters validationParameters, SecurityToken& validatedToken)
at Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler.HandleAuthenticateAsync()
[20:47:47 INF] BearerIdentityServerAuthenticationJwt was not authenticated. Failure message: IDX10214: Audience validation failed. Audiences: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]'. Did not match: validationParameters.ValidAudience: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]' or validationParameters.ValidAudiences: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]'.
[20:47:47 INF] Bearer was not authenticated. Failure message: IDX10214: Audience validation failed. Audiences: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]'. Did not match: validationParameters.ValidAudience: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]' or validationParameters.ValidAudiences: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]'.
[20:47:47 INF] Authorization failed.
[20:47:47 INF] AuthenticationScheme: BearerIdentityServerAuthenticationJwt was challenged.
[20:47:47 INF] AuthenticationScheme: Bearer was challenged.
[20:47:47 INF] Request finished in 13.2351ms 401
Yeah, that still looks like your proxy isn't setup right. Did you verify your X-Forward headers?
I'm using Apache and have this, which has been working well so far until this recent issue:
ProxyPass / http://localhost:5000/
ProxyPassReverse / http://localhost:5000/
RemoteIPHeader X-Forwarded-For
RemoteIPTrustedProxy 127.0.0.1
I am seeing HTTP 401 errors in the Apache logs (for example):
64.233.173.43 - - [25/Sep/2020:06:47:47 +1000] "POST /smarthome HTTP/1.1" 401 3954 "-" "Mozilla/5.0 (compatible; Google-Cloud-Functions/2.1; +http://www.google.com/bot.html)"
There are 3 different IPs:
I see you passing the X-Forwarded-For
header, but NOT the X-Forwarded-Proto
header.
I haven't used Apache in many years, but I think you also need something like
RequestHeader set X-Forwarded-Proto https
Oh yes, missed that. I added that into the Apache config. Restarted Apache Tried to relink and got the same error:
[22:29:38 INF] Request starting HTTP/1.1 POST http://localhost:5000/smarthome application/json;charset=UTF-8 79
[22:29:38 INF] Failed to validate the token.
Microsoft.IdentityModel.Tokens.SecurityTokenInvalidAudienceException: IDX10214: Audience validation failed. Audiences: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]'. Did not match: validationParameters.ValidAudience: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]' or validationParameters.ValidAudiences: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]'.
at Microsoft.IdentityModel.Tokens.Validators.ValidateAudience(IEnumerable`1 audiences, SecurityToken securityToken, TokenValidationParameters validationParameters)
at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateAudience(IEnumerable`1 audiences, JwtSecurityToken jwtToken, TokenValidationParameters validationParameters)
at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateTokenPayload(JwtSecurityToken jwtToken, TokenValidationParameters validationParameters)
at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateToken(String token, TokenValidationParameters validationParameters, SecurityToken& validatedToken)
at Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler.HandleAuthenticateAsync()
[22:29:38 INF] BearerIdentityServerAuthenticationJwt was not authenticated. Failure message: IDX10214: Audience validation failed. Audiences: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]'. Did not match: validationParameters.ValidAudience: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]' or validationParameters.ValidAudiences: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]'.
[22:29:38 INF] Bearer was not authenticated. Failure message: IDX10214: Audience validation failed. Audiences: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]'. Did not match: validationParameters.ValidAudience: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]' or validationParameters.ValidAudiences: '[PII is hidden. For more details, see https://aka.ms/IdentityModel/PII.]'.
[22:29:38 INF] Authorization failed.
[22:29:38 INF] AuthenticationScheme: BearerIdentityServerAuthenticationJwt was challenged.
[22:29:38 INF] AuthenticationScheme: Bearer was challenged.
[22:29:38 INF] Request finished in 6.2319ms 401
Actually the HTTP 401 could be due to trust settings - I will do some reading on that.
Tried a couple of RemoteIPTrustedProxy values (i.e. 127.0.0.1 and localhost) but this still didn't affect the outcome.
It is curious that this POST is returning a 401 error:
64.233.173.43 - - [25/Sep/2020:06:47:47 +1000] "POST /smarthome HTTP/1.1" 401
I guess that could be the crux of the issue.
The fact you are still getting localhost:5000
in your log is odd. Mine shows the external address, and the app root,, e.g.
2020-09-24 22:47:36.200 +00:00 [Information] Request starting HTTP/1.1 POST http://MYPUBLICDOMAIN.COM/google/home/smarthome application/json;charset=UTF-8 299
Thus why I question your proxy config. You can set the logPII to true so you can see what values it thinks its dealing with there. It could provide some pointers for where your configuration is wrong.
{
"deviceConfigFile": "config/googleDevices.json",
"logPII": true,
Is that POST line the app reporting what it is about to do? or the request received from Google?
[22:29:38 INF] Request starting HTTP/1.1 POST http://localhost:5000/smarthome application/json;charset=UTF-8 79
Righto - had to add another Apache setting ProxyPreserveHost On
, so I have:
ProxyPreserveHost On
ProxyPass / http://127.0.0.1:5000/
ProxyPassReverse / http://127.0.0.1:5000/
RequestHeader set "X-Forwarded-Proto" expr=%{REQUEST_SCHEME}
# For good measure:
RequestHeader set X-Forwarded-Protocol https
RequestHeader set X-Forwarded-SSL on
RequestHeader set X-Url-Scheme https
This means I was not getting http://googlehome.<mydomain>/smarthome
requests but it still gave a 401 at the same point:
[08:02:58 INF] Request starting HTTP/1.1 POST http://googlehome.figntigger.id.au/smarthome application/json;charset=UTF-8 79
[08:02:58 INF] Failed to validate the token.
Microsoft.IdentityModel.Tokens.SecurityTokenInvalidAudienceException: IDX10214: Audience validation failed. Audiences: 'empty'. Did not match: validationParameters.ValidAudience: 'HomeAutio.Mqtt.GoogleHome' or validationParameters.ValidAudiences: 'null'.
at Microsoft.IdentityModel.Tokens.Validators.ValidateAudience(IEnumerable`1 audiences, SecurityToken securityToken, TokenValidationParameters validationParameters)
at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateAudience(IEnumerable`1 audiences, JwtSecurityToken jwtToken, TokenValidationParameters validationParameters)
at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateTokenPayload(JwtSecurityToken jwtToken, TokenValidationParameters validationParameters)
at System.IdentityModel.Tokens.Jwt.JwtSecurityTokenHandler.ValidateToken(String token, TokenValidationParameters validationParameters, SecurityToken& validatedToken)
at Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler.HandleAuthenticateAsync()
[08:02:58 INF] BearerIdentityServerAuthenticationJwt was not authenticated. Failure message: IDX10214: Audience validation failed. Audiences: 'empty'. Did not match: validationParameters.ValidAudience: 'HomeAutio.Mqtt.GoogleHome' or validationParameters.ValidAudiences: 'null'.
[08:02:58 INF] Bearer was not authenticated. Failure message: IDX10214: Audience validation failed. Audiences: 'empty'. Did not match: validationParameters.ValidAudience: 'HomeAutio.Mqtt.GoogleHome' or validationParameters.ValidAudiences: 'null'.
[08:02:58 INF] Authorization failed.
[08:02:58 INF] AuthenticationScheme: BearerIdentityServerAuthenticationJwt was challenged.
[08:02:58 INF] AuthenticationScheme: Bearer was challenged.
[08:02:58 INF] Request finished in 4.0065ms 401
As a last ditch effort, I removed the tokens.json file, restarted the contain and still got the error above.
X-Forwarded-For
AND X-Forwarded-Proto
from your proxy. -e ASPNETCORE_PATHBASE="/google/home"
in it. This is only needed if you are proxying at a NON-root location (in that case, /google/home/
).Also, you are unlinking, and then linking again, not RElinking right? The latter didn't appear to actually force you to re-login and re-issue tokens, it would reuse the old one.
I have found a way to reproduce, and I think your issue has something to do with the IdentityServer4 upgrade as well. Im asking them what to do with it.
Try the latest I just pushed. I suspect the IdentityServer4 documentation was woefully lacking around this new "simple" method they introduced. I added back the resource wrapping that they claim is no longer necessary and mine's working again.
Working!
The issue was the ASPNETCORE_PATHBASE
- I can't believe I missed that.
So, I just removed the -e ASPNETCORE_PATHBASE="/google/home"
and it is working.
In fact, faster than before.
Nice, glad to hear it! Feel free to close this if you're good now!
I am feeling embarrassed raising all these issues.
Today I couldn't re-link and got these errors in the logs:
Have you seen these before Michael?