[PushedAuthorizationRequests] we are getting some error logs from duende
Closed this issue · 9 comments
Duende IdentityServer- 7.0.6
.NET- 8
Since we updated to Duende IdentityServer to- 7.0.6 we are getting some error logs from duende
Failed executing DbCommand ("17"ms) [Parameters=["@__p_0='?' (DbType = Int32)"], CommandType='Text', CommandTimeout='30']"
""DELETE FROM [p]
FROM [PushedAuthorizationRequests] AS [p]
WHERE [p].[Id] IN (
SELECT TOP(@__p_0) [p0].[Id]
FROM [PushedAuthorizationRequests] AS [p0]
WHERE [p0].[ExpiresAtUtc] < GETUTCDATE()
ORDER BY [p0].[ExpiresAtUtc]
)"
Any idea what is causing this issue and what could be appropriate solution?
There is no changes mentioned related to [PushedAuthorizationRequests]
table in the release note https://docs.duendesoftware.com/identityserver/v7/upgrades/v6.3_to_v7.0/
New in IdentityServer 7, we added support for pushed authorization requests. This failure is coming from the background job that runs periodically to clean up pushed requests that have not been consumed. The release notes mention the new table here:
A new table has been added to store pushed authorization requests. This new table contains a hashed identifier, the pushed parameters (as a string, serialized and data protected), and the expiration time of the request.
And then it goes on to describe how to update your schema, depending on how you are implementing the store. It looks like you're using our EF based implementation, so if you applied an EF migration, that table should have been created for you.
I would expect that this failing database call would log more details about the nature of the failure. Do you see anything there? Are you able to query the pushed authorizations? If so, how many expired records are in the table? Does every attempt to clean up the table fail (we can infer this based on how frequently and regularly you get this error message, as the cleanup job runs on a fixed, configurable schedule).
Here are some more related logs
Tried to remove {grantCount} expired grants, but only {deleteCount} was deleted. This indicates that another process has already removed the items. message:Tried to remove 1 expired grants, but only 0 was deleted. This indicates that another process has already removed the items.
Exception removing expired grants: "Invalid object name 'PushedAuthorizationRequests'." fields.exception:Invalid object name 'PushedAuthorizationRequests'.
The table we created is named "PushedAuthorizationRequest" following the model provided by "Duende.IdentityServer.EntityFramework.Entities." However, there seems to be an issue where the system is looking for a table called "PushedAuthorizationRequests" instead
Also i am not seeing any record created in the PushedAuthorizationRequest. It is always empty.
Pushed authorization requests are normally consumed right after they are created - usually a client would push parameters and then call authorize immediately. If that succeeds, the record gets deleted when authorization completes. The cleanup job is there to remove records that are left over from failures.
The log message about trying to delete 1 but not seeing any suggests that you have a load balanced environment and multiple nodes are trying to clean up simultaneously. I don't think there's an issue with the table name, as you're clearly able to query the table (since the log indicates that a record was expected to be deleted).
My recommendation is (assuming you do have multiple load balanced nodes), try to configure those nodes such that only one has the cleanup job enabled. The specifics for your environment will vary with the hosting and load balancing tools that you're using, but the goal is to disable the cleanup jobs everywhere except 1 container.
@Rahul21199 Did Joe's comment help you out? If so I would like to close this issue.
@josephdecock / @RolandGuijt
We've checked the QA environment, and there’s no load balancer configured, yet we’re still encountering this error.
Additionally, it seems we aren’t getting any entries for this table. I’ve checked multiple times, and the table is blank with the index set to zero.
@josephdecock / @RolandGuijt Please see the more findings below
The issue appears to be with the table name. The job is attempting to delete data from "PushedAuthorizationRequests" instead of "PushedAuthorizationRequest." The table "PushedAuthorizationRequest" was created based on the model provided by "Duende.IdentityServer.EntityFramework.Entities."
Please see the observations below:
-
The logs indicate an error: "Invalid object name 'PushedAuthorizationRequests'," suggesting the job is trying to access the "PushedAuthorizationRequests" table.
-
When I created a new table named "PushedAuthorizationRequests," the error logs disappeared, confirming that the job was indeed trying to access that table.
We could create a table named "PushedAuthorizationRequests," but we're uncertain about how this might affect the authorization flow internally.
Could you please look into this and fix the issue?
when i followed https://github.com/DuendeSoftware/IdentityServer/blob/main/migrations/IdentityServerDb/Migrations/PersistedGrantDb.sql#L57
seems table name should be PushedAuthorizationRequests only.
Feel free to share if it will have any impact.
Thanks. Closing this issue but if there's something to add, please do so.