Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Fusionauth does not display the provider associated with an application when the following error occurs io.fusionauth.api.service.cache.DistributedCacheNotifier - Cache reload request failed #2978

Open
konvergence opened this issue Jan 23, 2025 · 2 comments
Open

Fusionauth does not display the provider associated with an application when the following error occurs io.fusionauth.api.service.cache.DistributedCacheNotifier - Cache reload request failed #2978

konvergence opened this issue Jan 23, 2025 · 2 comments

Comments

@konvergence
Copy link

Fusionauth does not display the provider associated with an application when the following error occurs io.fusionauth.api.service.cache.DistributedCacheNotifier - Cache reload request failed

Description

A clear and concise description of what the bug is.

we see the following error on pod, each time we try to update any provider

2025-01-23 09:57:00.706 AM ERROR io.fusionauth.app.primeframework.error.ExceptionExceptionHandler - An unhandled exception was thrown
java.lang.NullPointerException: null
2025-01-23 09:57:00.707 AM ERROR io.fusionauth.api.service.cache.DistributedCacheNotifier - Failed to request a cache reload for [CORSConfiguration, IdentityProvider, JSONWebKeys] on [http://10.42.17.253:9011]. Status Code [500]
Took [532] ms

Observed versions

1.53.3

Affects versions

.

Steps to reproduce

Steps to reproduce the behavior:

  1. Go to 'identiry provider
  2. Click on Edit on selected identity provider
  3. Save it
@konvergence
Copy link
Author

konvergence commented Jan 26, 2025 •
edited
Loading

After restart,
We get this error

Starting fusionauth-app...
  --> Logging to /usr/local/fusionauth/logs/fusionauth-app.log
2025-01-25 10:30:55.916 AM INFO  io.fusionauth.api.configuration.DefaultFusionAuthConfiguration - Loading FusionAuth configuration file [/usr/local/fusionauth/config/fusionauth.properties]
2025-01-25 10:30:55.942 AM INFO  io.fusionauth.api.configuration.DefaultFusionAuthConfiguration - Dynamically set property [fusionauth-app.url] set to [http://10.42.50.146:9011]
2025-01-25 10:30:55.943 AM INFO  com.inversoft.configuration.BasePropertiesFileInversoftConfiguration - 
  - Overriding default value of property [database.mysql.enforce-utf8mb4] with value [true]
  - Overriding default value of property [FUSIONAUTH_APP_RUNTIME_MODE] with value [development]
  - Overriding default value of property [SEARCH_TYPE] with value [database]
2025-01-25 10:30:55.980 AM INFO  io.fusionauth.api.configuration.DefaultFusionAuthConfiguration - Loading FusionAuth configuration file [/usr/local/fusionauth/config/fusionauth.properties]
2025-01-25 10:30:55.981 AM INFO  io.fusionauth.api.configuration.DefaultFusionAuthConfiguration - Dynamically set property [fusionauth-app.url] set to [http://10.42.50.146:9011]
2025-01-25 10:30:55.982 AM INFO  com.inversoft.configuration.BasePropertiesFileInversoftConfiguration - 
  - Overriding default value of property [database.mysql.enforce-utf8mb4] with value [true]
  - Overriding default value of property [FUSIONAUTH_APP_RUNTIME_MODE] with value [development]
  - Overriding default value of property [SEARCH_TYPE] with value [database]
2025-01-25 10:30:56.331 AM INFO  io.fusionauth.api.configuration.DefaultFusionAuthConfiguration - Loading FusionAuth configuration file [/usr/local/fusionauth/config/fusionauth.properties]
2025-01-25 10:30:56.332 AM INFO  io.fusionauth.api.configuration.DefaultFusionAuthConfiguration - Dynamically set property [fusionauth-app.url] set to [http://10.42.50.146:9011]
2025-01-25 10:30:56.332 AM INFO  com.inversoft.configuration.BasePropertiesFileInversoftConfiguration - 
  - Overriding default value of property [database.mysql.enforce-utf8mb4] with value [true]
  - Overriding default value of property [FUSIONAUTH_APP_RUNTIME_MODE] with value [development]
  - Overriding default value of property [SEARCH_TYPE] with value [database]
2025-01-25 10:30:56.466 AM INFO  com.inversoft.maintenance.MaintenanceModePoller - Poller started to Wait for configuration to be completed.
2025-01-25 10:30:56.467 AM INFO  io.fusionauth.app.primeframework.FusionHTTPContextAuthSetup - Initializing the FusionAuth HTTP Context.
2025-01-25 10:30:57.025 AM INFO  com.inversoft.maintenance.db.JDBCMaintenanceModeDatabaseService - [Kli23A] Database Version [1.53.0]
2025-01-25 10:30:57.031 AM INFO  com.inversoft.maintenance.db.JDBCMaintenanceModeDatabaseService - [Kli23A] Latest Migration Version [1.53.0]
2025-01-25 10:30:57.035 AM INFO  io.fusionauth.app.guice.FusionAuthModule - 
---------------------------------------------------------------------------------------------------------
--------------------------------- Starting FusionAuth version [1.53.3] ----------------------------------
---------------------------------------------------------------------------------------------------------
2025-01-25 10:30:57.216 AM INFO  io.fusionauth.api.plugin.guice.PluginModule - No plugins found
2025-01-25 10:30:57.321 AM INFO  io.fusionauth.api.service.system.NodeService - Node [6d74b471-ee44-4883-84d1-320fff979580] started.
2025-01-25 10:30:57.772 AM INFO  io.fusionauth.api.configuration.DefaultFusionAuthConfiguration - Loading FusionAuth configuration file [/usr/local/fusionauth/config/fusionauth.properties]
2025-01-25 10:30:57.772 AM INFO  io.fusionauth.api.configuration.DefaultFusionAuthConfiguration - Dynamically set property [fusionauth-app.url] set to [http://10.42.50.146:9011]
2025-01-25 10:30:57.773 AM INFO  com.inversoft.configuration.BasePropertiesFileInversoftConfiguration - 
  - Overriding default value of property [database.mysql.enforce-utf8mb4] with value [true]
  - Overriding default value of property [FUSIONAUTH_APP_RUNTIME_MODE] with value [development]
  - Overriding default value of property [SEARCH_TYPE] with value [database]
2025-01-25 10:30:57.774 AM INFO  com.inversoft.jdbc.hikari.DataSourceProvider - Connecting to PostgreSQL database at [jdbc:postgresql://postgres:5432/fusionauth]
2025-01-25 10:30:57.781 AM INFO  com.zaxxer.hikari.HikariDataSource - Database-background - Starting...
2025-01-25 10:30:57.853 AM INFO  com.zaxxer.hikari.HikariDataSource - Database-background - Start completed.
2025-01-25 10:30:58.619 AM INFO  com.inversoft.jdbc.hikari.DataSourceProvider - Connecting to PostgreSQL database at [jdbc:postgresql://postgres:5432/fusionauth]
2025-01-25 10:30:58.620 AM INFO  com.zaxxer.hikari.HikariDataSource - Database-primary - Starting...
2025-01-25 10:30:58.660 AM INFO  com.zaxxer.hikari.pool.HikariPool - Database-primary - Added connection org.postgresql.jdbc.PgConnection@538b3c88
2025-01-25 10:30:58.661 AM INFO  com.zaxxer.hikari.HikariDataSource - Database-primary - Start completed.
2025-01-25 10:30:58.952 AM INFO  com.inversoft.jdbc.hikari.DataSourceProvider - Connecting to PostgreSQL database at [jdbc:postgresql://postgres:5432/fusionauth]
2025-01-25 10:30:58.952 AM INFO  com.zaxxer.hikari.HikariDataSource - Database-secondary - Starting...
2025-01-25 10:30:58.972 AM INFO  com.zaxxer.hikari.pool.HikariPool - Database-secondary - Added connection org.postgresql.jdbc.PgConnection@3a588b5f
2025-01-25 10:30:58.973 AM INFO  com.zaxxer.hikari.HikariDataSource - Database-secondary - Start completed.
2025-01-25 10:30:59.463 AM INFO  com.inversoft.scheduler.DefaultScheduler - Starting up scheduler
2025-01-25 10:30:59.464 AM INFO  com.inversoft.scheduler.DefaultScheduler - Scheduler is running
2025-01-25 10:30:59.756 AM INFO  io.fusionauth.api.service.system.NodeService - Node [6d74b471-ee44-4883-84d1-320fff979580] added with address [http://10.42.50.146:9011]
2025-01-25 10:31:01.013 AM ERROR com.inversoft.scheduler.LogAndRetainFailureHandler - The scheduled service [class io.fusionauth.api.service.cache.IdentityProviderCacheLoader] failed but will be re-run.
java.lang.NullPointerException: Cannot invoke "String.toLowerCase()" because "name" is null
	at com.inversoft.http.Cookie.addAttribute(Cookie.java:192)
	at com.inversoft.http.Cookie.fromResponseHeader(Cookie.java:178)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
	at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1708)
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509)
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
	at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:151)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:174)
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
	at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596)
	at com.inversoft.rest.ClientResponse.setHeaders(ClientResponse.java:129)
	at com.inversoft.rest.RESTClient.go(RESTClient.java:410)
	at io.fusionauth.api.service.identity.OpenIdConnectIdentityProviderHelper.resolveOpenIDConnectEndpoints(OpenIdConnectIdentityProviderHelper.java:80)
	at io.fusionauth.api.service.cache.IdentityProviderCacheLoader.retrieveAllAndResolveOpenIDConnectEndpoints(IdentityProviderCacheLoader.java:73)
	at io.fusionauth.api.service.cache.IdentityProviderCacheLoader.internalLoad(IdentityProviderCacheLoader.java:53)
	at com.inversoft.cache.BaseCacheLoader.load(BaseCacheLoader.java:21)
	at io.fusionauth.api.service.cache.IdentityProviderCacheLoader.run(IdentityProviderCacheLoader.java:48)
	at com.inversoft.scheduler.InjectableRunnable.run(InjectableRunnable.java:56)
	at com.inversoft.scheduler.DefaultScheduler.<init>(DefaultScheduler.java:70)
	at com.inversoft.scheduler.DefaultScheduler$$FastClassByGuice$$9d355ca.GUICE$TRAMPOLINE(<generated>)
	at com.inversoft.scheduler.DefaultScheduler$$FastClassByGuice$$9d355ca.apply(<generated>)
	at com.google.inject.internal.DefaultConstructionProxyFactory$FastClassProxy.newInstance(DefaultConstructionProxyFactory.java:82)
	at com.google.inject.internal.ConstructorInjector.provision(ConstructorInjector.java:114)
	at com.google.inject.internal.ConstructorInjector.construct(ConstructorInjector.java:91)
	at com.google.inject.internal.ConstructorBindingImpl$Factory.get(ConstructorBindingImpl.java:300)
	at com.google.inject.internal.ProviderToInternalFactoryAdapter.get(ProviderToInternalFactoryAdapter.java:40)
	at com.google.inject.internal.SingletonScope$1.get(SingletonScope.java:169)
	at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:45)
	at com.google.inject.internal.FactoryProxy.get(FactoryProxy.java:60)
	at com.google.inject.internal.InternalInjectorCreator.loadEagerSingletons(InternalInjectorCreator.java:213)
	at com.google.inject.internal.InternalInjectorCreator.injectDynamically(InternalInjectorCreator.java:186)
	at com.google.inject.internal.InternalInjectorCreator.build(InternalInjectorCreator.java:113)
	at com.google.inject.Guice.createInjector(Guice.java:87)
	at com.google.inject.Guice.createInjector(Guice.java:69)
	at com.google.inject.Guice.createInjector(Guice.java:59)
	at org.primeframework.mvc.guice.GuiceBootstrap.initialize(GuiceBootstrap.java:60)
	at org.primeframework.mvc.BasePrimeMain.hup(BasePrimeMain.java:69)
	at org.primeframework.mvc.BasePrimeMain.start(BasePrimeMain.java:100)
	at io.fusionauth.app.FusionAuthMain.main(FusionAuthMain.java:27)
2025-01-25 10:31:01.364 AM INFO  com.inversoft.search.ElasticRestClientHelper - Connecting to Elasticsearch at [http://localhost:9021]
2025-01-25 10:31:01.440 AM INFO  com.inversoft.search.ElasticRestClientHelper - Connecting to Elasticsearch at [http://localhost:9021]
2025-01-25 10:31:01.612 AM INFO  io.fusionauth.app.primeframework.FusionHTTPContextAuthSetup - Initializing the FusionAuth HTTP Context.
2025-01-25 10:31:01.766 AM INFO  org.primeframework.mvc.PrimeMVCRequestHandler - Initializing Prime
2025-01-25 10:31:01.767 AM INFO  org.primeframework.mvc.PrimeMVCRequestHandler - Initializing Prime
2025-01-25 10:31:01.768 AM INFO  io.fusionauth.http.server.HTTPServer - Starting the HTTP server. Buckle up!
2025-01-25 10:31:01.772 AM INFO  io.fusionauth.http.server.HTTPServer - HTTP server listening on port [9011]
2025-01-25 10:31:01.773 AM INFO  io.fusionauth.http.server.HTTPServer - HTTP server started successfully
2025-01-25 10:31:01.773 AM INFO  io.fusionauth.http.server.HTTPServer - Starting the HTTP server. Buckle up!
2025-01-25 10:31:01.774 AM INFO  io.fusionauth.http.server.HTTPServer - HTTP server listening on port [9012]
2025-01-25 10:31:01.774 AM INFO  io.fusionauth.http.server.HTTPServer - HTTP server started successfully

@konvergence
Copy link
Author

Under audit log we have identified the IdP that cause the error

Unable to resolve OpenID Connect configuration using issuer [https://auth1-recette.labanquepostale.com/IdPOAuth2/idpoidc2] for [OIDC La Banque postale KCSR IdP TEST].
Request to the [https://auth1-recette.labanquepostale.com/IdPOAuth2/idpoidc2/.well-known/openid-configuration] endpoint failed.
Status code [-1]

We done a chrome test with HAR export to check the cookies, and see that the provider add a ; at the end of a cookie

{
              "name": "Set-Cookie",
              "value": "TS01450392=01f2da9e0a8c89143113ab2183bf83d91a43cdcbe1ed1b09903a90fedbd4d0c1ec2649d836787ac700eac3a76f9cb22410bf3c1e34; Path=/; Secure; HttpOnly;"
            },
            {
              "name": "Set-Cookie",
              "value": "TS01bed27b=01f2da9e0a71c0deeadf983470474b434d88f51ba1ed1b09903a90fedbd4d0c1ec2649d836f61ba560005ecb38ce49fc2f236cb8bf85411963e8f58a6deb2af1e347df1209; path=/IdPOAuth2; HttpOnly; Secure"
            },
            {
              "name": "Set-Cookie",
              "value": "TS7bbc29a1027=0851d0431fab200058710c55834a03c333694e5a9ea840cc06faeeeffcaa9ff066c3272903bab1c208d1021acc1130005a2c6c91535ad4abf22322366f3f248ad6ecd04ffadd8fc811ae9de3cc664848e466ee26d21f22a5ee652af1106e7093; Path=/"
            }

this is exactly the same issue than here inversoft/restify#11 (comment)

It's not acceptable for fusionauth to completely block its operation because only one supplier returns a cookie with a semicolon at the end of the value.

We've already proposed a pull request here inversoft/restify#12 for more secure library behavior
and we'd also need to correct fusionauth's behavior, so as not to block its entire operation because of a single provider.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@konvergence