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.

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

Tenant Delete may continue even if deleting the users in the tenant fails #2307

Closed
jobannon opened this issue Jun 6, 2023 · 2 comments
Closed
Assignees
Labels
bug Something isn't working
Milestone

Comments

@jobannon
Copy link

jobannon commented Jun 6, 2023

Description

When we delete a tenant, we must first delete all records with a FK to the tenant table.

If deleting the users fails, or times out for some other reason, we may continue to attempt to delete the tenant.

This causes some noise in the logs due to attempted FK violations.

Observed in version

1.45.1

Affects versions

TBD

Expected behavior

When FusionAuth fails to delete users, or any other record with a FK to the tenant table, the delete tenant job should end up in the correct state, and the operation should in a state to be retried.

Additional context

In the case where this was observed, the database as busy, and we timed out waiting to get a connection to complete deleting the users.

If we encounter this type of an exception we should exist the delete process, and leave the system in a state where the operation can be retried. We may also want to catch particular exceptions and retry the delete process to see if we can get it to complete without user interaction.

2023-06-05 11:00:25.539 PM ERROR io.fusionauth.api.service.system.task.FailSafeRunnable - A [DeleteTenant] async task threw an exception.
org.apache.ibatis.exceptions.PersistenceException:
### Error updating database.  Cause: org.postgresql.util.PSQLException: ERROR: update or delete on table "tenants" violates foreign key constraint "users_fk_1" on table "users"
  Detail: Key (id)=(<redacted>) is still referenced from table "users".
### The error may exist in io/fusionauth/api/domain/TenantMapper.xml
### The error may involve defaultParameterMap
### The error occurred while setting parameters
### SQL: DELETE       FROM tenants       WHERE id = ?
### Cause: org.postgresql.util.PSQLException: ERROR: update or delete on table "tenants" violates foreign key constraint "users_fk_1" on table "users"
  Detail: Key (id)=(<redacted>) is still referenced from table "users".
        at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:30)
        at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:196)
        at org.apache.ibatis.session.defaults.DefaultSqlSession.delete(DefaultSqlSession.java:209)
        at jdk.internal.reflect.GeneratedMethodAccessor47.invoke(Unknown Source)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:568)
        at org.apache.ibatis.session.SqlSessionManager$SqlSessionInterceptor.invoke(SqlSessionManager.java:357)
        at jdk.proxy2/jdk.proxy2.$Proxy52.delete(Unknown Source)
        at org.apache.ibatis.session.SqlSessionManager.delete(SqlSessionManager.java:256)
        at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:72)
        at org.apache.ibatis.binding.MapperProxy$PlainMethodInvoker.invoke(MapperProxy.java:145)
        at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:86)
        at jdk.proxy2/jdk.proxy2.$Proxy84.delete(Unknown Source)
        at io.fusionauth.api.service.system.DefaultTenantService.delete(DefaultTenantService.java:286)
        at io.fusionauth.api.service.system.task.DeleteTenantTask.lambda$get$0(DeleteTenantTask.java:33)
        at io.fusionauth.api.service.system.task.FailSafeRunnable.run(FailSafeRunnable.java:37)
        at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: org.postgresql.util.PSQLException: ERROR: update or delete on table "tenants" violates foreign key constraint "users_fk_1" on table "users"
  Detail: Key (id)=(<redacted>) is still referenced from table "users".
        at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2676)
        at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2366)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:356)
        at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:496)
        at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:413)
        at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:190)
        at org.postgresql.jdbc.PgPreparedStatement.execute(PgPreparedStatement.java:177)
        at com.zaxxer.hikari.pool.ProxyPreparedStatement.execute(ProxyPreparedStatement.java:44)
        at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.execute(HikariProxyPreparedStatement.java)
        at org.apache.ibatis.executor.statement.PreparedStatementHandler.update(PreparedStatementHandler.java:47)
        at org.apache.ibatis.executor.statement.RoutingStatementHandler.update(RoutingStatementHandler.java:74)
        at org.apache.ibatis.executor.SimpleExecutor.doUpdate(SimpleExecutor.java:50)
        at org.apache.ibatis.executor.BaseExecutor.update(BaseExecutor.java:117)
        at org.apache.ibatis.executor.CachingExecutor.update(CachingExecutor.java:76)
        at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:194)
        ... 15 common frames omitted

At the end of the system logs

2023-06-05 11:00:51.005 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] has completed successful.
2023-06-05 11:00:51.007 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] failed to complete. You may need to retry the request. Please view the EventLog for additional information.
2023-06-05 11:00:51.008 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] failed to complete. You may need to retry the request. Please view the EventLog for additional information.
2023-06-05 11:00:51.010 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] failed to complete. You may need to retry the request. Please view the EventLog for additional information.
2023-06-05 11:00:51.011 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] failed to complete. You may need to retry the request. Please view the EventLog for additional information.
2023-06-05 11:00:51.012 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] has completed successful.
2023-06-05 11:00:51.013 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] has completed successful.
2023-06-05 11:00:51.013 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] has completed successful.
2023-06-05 11:00:51.015 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] failed to complete. You may need to retry the request. Please view the EventLog for additional information.
2023-06-05 11:00:51.015 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] has completed successful.
2023-06-05 11:00:51.016 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] has completed successful.
2023-06-05 11:00:51.016 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] has completed successful.
2023-06-05 11:00:51.017 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] failed to complete. You may need to retry the request. Please view the EventLog for additional information.
2023-06-05 11:00:51.019 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] failed to complete. You may need to retry the request. Please view the EventLog for additional information.
2023-06-05 11:00:51.020 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] failed to complete. You may need to retry the request. Please view the EventLog for additional information.
2023-06-05 11:00:51.022 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] failed to complete. You may need to retry the request. Please view the EventLog for additional information.
2023-06-05 11:00:51.022 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] has completed successful.
2023-06-05 11:00:51.023 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] failed to complete. You may need to retry the request. Please view the EventLog for additional information.
2023-06-05 11:00:51.024 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] has completed successful.
2023-06-05 11:00:51.025 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] failed to complete. You may need to retry the request. Please view the EventLog for additional information.
2023-06-05 11:00:51.026 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] failed to complete. You may need to retry the request. Please view the EventLog for additional information.
2023-06-05 11:00:51.027 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] failed to complete. You may need to retry the request. Please view the EventLog for additional information.
2023-06-05 11:00:51.028 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] has completed successful.
2023-06-05 11:00:51.029 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] has completed successful.
2023-06-05 11:00:51.029 PM INFO  io.fusionauth.api.service.system.DefaultAsyncTaskManager - [redacted] [DeleteTenant] task for [redacted] has completed successful.

Internal

  • Ticket 73569
  • Ticket 73577

Community guidelines

All issues filed in this repository must abide by the FusionAuth community guidelines.

Release Notes

When using the asynchronous tenant delete, it is possible for the delete job to fail if the system is under heavy load. When this occurs the delete job status may not be correctly updated and you are stuck in a Deleting state. The asynchronous job processor has been enhanced to account for this potential failure condition so the the job can be correctly restarted if necessary.

@jobannon jobannon added the bug Something isn't working label Jun 6, 2023
@jobannon jobannon changed the title Tenants Stuck in a Deleting State Removing a Tenant operation can occasionally fail. Jun 6, 2023
@jobannon jobannon changed the title Removing a Tenant operation can occasionally fail. Tenant Delete does not fail correctly if dependent actions fail Jun 6, 2023
@jobannon jobannon changed the title Tenant Delete does not fail correctly if dependent actions fail Tenant Delete does not exit correctly if dependent actions fail Jun 6, 2023
@robotdan robotdan changed the title Tenant Delete does not exit correctly if dependent actions fail Tenant Delete may continue even if deleting the users in the tenant fails Jun 7, 2023
@robotdan robotdan added this to Backlog in FusionAuth Issues via automation Jun 7, 2023
@spwitt
Copy link

spwitt commented Jun 8, 2023

It would be good to abandon the operation if one of the steps to delete the tenant fails, but this error would have been recoverable if not for the exhausted database connection pool.

The persistence exception for deleting the tenant should have triggered updating the state of the tenant back to Active, but it was unable to complete this because there were no database connections available. It also could not create an Event Log for the failed operation for the same reason.

@spwitt spwitt self-assigned this Jul 10, 2023
@spwitt spwitt moved this from Backlog to In progress in FusionAuth Issues Jul 10, 2023
@spwitt spwitt added this to the 1.48.0 milestone Aug 15, 2023
@spwitt spwitt moved this from In progress to Code complete in FusionAuth Issues Aug 15, 2023
@spwitt
Copy link

spwitt commented Aug 15, 2023

@spwitt spwitt moved this from Code complete to Reviewer approved in FusionAuth Issues Aug 23, 2023
@robotdan robotdan moved this from Reviewer approved to Code complete in FusionAuth Issues Oct 11, 2023
@robotdan robotdan moved this from Code complete to Delivered in FusionAuth Issues Oct 30, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
FusionAuth Issues
  
Delivered
Development

No branches or pull requests

3 participants