Circ Rules and Loan Policies
(UXPROD-789)
|
|
| Status: | Closed |
| Project: | mod-patron-blocks |
| Components: | None |
| Affects versions: | None |
| Fix versions: | None | Parent: | Circ Rules and Loan Policies |
| Type: | Bug | Priority: | P1 |
| Reporter: | Anya | Assignee: | Unassigned |
| Resolution: | Done | Votes: | 1 |
| Labels: | Showstopper-Cornell, support | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original estimate: | Not Specified | ||
| Attachments: |
|
||||||||||||||||||||||||||||||||||||||||
| Issue links: |
|
||||||||||||||||||||||||||||||||||||||||
| Sprint: | |||||||||||||||||||||||||||||||||||||||||
| Development Team: | Vega | ||||||||||||||||||||||||||||||||||||||||
| Release: | R2 2021 Hot Fix #7 | ||||||||||||||||||||||||||||||||||||||||
| CSP Approved: | Yes | ||||||||||||||||||||||||||||||||||||||||
| CSP Request Details: | Approved via release_bug_triage Slack channel. | ||||||||||||||||||||||||||||||||||||||||
| Potential Workaround: | Original issue reported by Cornell (this ticket, 1 and 2 seem to have the same root cause - some of the FEE_FINE_BALANCE_CHANGE messages are not delivered from mod-feesfines to mod-patron-blocks for some reason. This would explain why it only happens sometimes and cannot be reproduced on other envs. It can be a pub-sub or Kafka issue and it can possibly affect other blocks. The fact that it happens after renewal in one case and after check-in in another case is, most probably, insignificant. Please check comment & workaround field in |
||||||||||||||||||||||||||||||||||||||||
| Affected Institution: |
Cornell, Spokane Public Libraries, TAMU, University of Chicago
|
||||||||||||||||||||||||||||||||||||||||
| Epic Link: | Circ Rules and Loan Policies | ||||||||||||||||||||||||||||||||||||||||
| RCA Group: | TBD | ||||||||||||||||||||||||||||||||||||||||
| Description |
|
Overview: Patron automatic blocks are aged to lost, then the patron renews them- but the block is not removed
Expected Results: the block is removed |
| Comments |
| Comment by Holly Mistlebauer [ 07/Jan/22 ] |
|
Holly assigned this to herself because she is going to see if this issue can be recreated on Kiwi. |
| Comment by Holly Mistlebauer [ 07/Jan/22 ] |
|
Anya or Debra Howell: Which block is triggered in Step #2 above? I want to test this exactly as it is occurring. Thanks... |
| Comment by Thomas Trutt [ 07/Jan/22 ] |
|
Hi Holly.. The block that is not being removed is the Maximum fee/fine block. I will add some screenshots for reference.
|
| Comment by Holly Mistlebauer [ 07/Jan/22 ] |
|
Anya and Debra Howell: I created a block on maximum number of items checked out. I'll see what happens... |
| Comment by Anya [ 07/Jan/22 ] |
|
I think the key is that it has to age to lost ... the try renewing and clear the block
|
| Comment by Thomas Trutt [ 07/Jan/22 ] |
|
correct Anya. This issue we have seen is:
I have tried to reproduce this in our test system by marking serval items as lost on a patron's account and then renewing them. This did not produce the same result as others are seeing. That said it could be automated vs manually marking an item as lost or hidden permission (I have a lot more permission then other staff). I have set up a test to hopefully reproduce this more closely to what other staff is seeing in production.
|
| Comment by Anya [ 10/Jan/22 ] |
|
Support : Holly Mistlebauer the support team has pumped this to a P1. |
| Comment by Holly Mistlebauer [ 10/Jan/22 ] |
|
Holly has tested this on Kiwi Bugfest and confirmed that it is an issue. This is the test she did...
|
| Comment by Holly Mistlebauer [ 10/Jan/22 ] |
|
Stephanie Buck: Just want to draw your attention to this P1 bug. |
| Comment by Stephanie Buck [ 10/Jan/22 ] |
|
Holly Mistlebauer, please assign the release field and connect it to the patron blocks epic. |
| Comment by Holly Mistlebauer [ 10/Jan/22 ] |
|
Thomas Trutt: I'll let Vega see if they can reproduce this. As I stated above, I did find a bug but not the same one as you. |
| Comment by Holly Mistlebauer [ 10/Jan/22 ] |
|
Stephanie Buck: This is a P1 bug so it needs to be fixed for Lotus. Thanks... |
| Comment by Holly Mistlebauer [ 10/Jan/22 ] |
|
Stephanie Buck: I searched JIRA for a UXPROD EPIC with "block" in the title and did not find one. Sorry... |
| Comment by Stephanie Buck [ 11/Jan/22 ] |
|
Thanks, Holly Mistlebauer. I was thinking of something else entirely - sorry. I think circ rules & loan policies is the best for now. |
| Comment by Alexander Kurash [ 12/Jan/22 ] |
|
Thomas TruttAnya Was this bug found in Kiwi or Juniper? |
| Comment by Debra Howell [ 12/Jan/22 ] |
|
Alexander Kurash - this bug is in Juniper |
| Comment by Debra Howell [ 12/Jan/22 ] |
|
Holly Mistlebauer and Stephanie Buck I would like to see this as a Hot Fix candidate. There is no workaround as this also impacts the OPAC. When the semester starts, this is going to be a huge problem. |
| Comment by Holly Mistlebauer [ 12/Jan/22 ] |
|
Alexander Kurash: I tested this bug on Kiwi Bugfest on Monday, just before I added the comment above. Let me see if there is a time attached to my comment... |
| Comment by Holly Mistlebauer [ 12/Jan/22 ] |
|
I can't figure out what time I tested on Monday...I just retested with just the a limit on the fee/fine balance and it worked correctly...I am going to test again from scratch and will let you know the exact time...thanks... |
| Comment by Holly Mistlebauer [ 12/Jan/22 ] |
|
Alexander Kurash: I just tested this on Kiwi following the steps below. It actually worked as expected. I will try my test from Monday again.
|
| Comment by Holly Mistlebauer [ 13/Jan/22 ] |
|
Alexander Kurash: I just reran the test I did on Monday. Here are the steps, with the times to look for in the logs...
(The time frame is 5:17 PM my time (in Arizona), which is 7:17 PM Eastern Time. I used the server time.) |
| Comment by Holly Mistlebauer [ 13/Jan/22 ] |
|
Alexander Kurash: In summary, I am not finding the same error as described by Cornell on Juniper, but I have found a related error on Kiwi. |
| Comment by Holly Mistlebauer [ 13/Jan/22 ] |
|
Stephanie Buck and Alexander Kurash: I have requested that this fix be made to Juniper as a hotfix. I'll let you know what I hear back. Thanks... |
| Comment by Thomas Trutt [ 13/Jan/22 ] |
|
I'm adding two more screenshots. I checked in the items in the hope that this would clear the block, but it appears it does not. Anya if I give you a timestamp as to when this happened on our production system would there be an issue passing the logs that Alexander Kurash is asking holly for? Alexander Kurash would that help? our production system is Juniper. |
| Comment by Anya [ 13/Jan/22 ] |
|
Yes with a time stamp I can get the logs for it. |
| Comment by Thomas Trutt [ 13/Jan/22 ] |
|
Thanks Anya . According to the fine/fee log, the items were renewed on 1-6-2022 at 1040am. The circulation log confirms that date and time as well with a Renewed through override entry. The user UUID is 04ba8ffa-e761-4bf0-813c-31c0c31ca1b3 .. If you need them Alexander Kurash I can also get you the item UUIDs as well as the fine/fee account UUIDs, please let me know. |
| Comment by Alexander Kurash [ 14/Jan/22 ] |
|
Thomas Trutt On your production system, do you see records like "... is not registered as PUBLISHER for event type ..." or "Response received with statusCode 400" (or 500) in mod-pubsub logs? Also, there is an endpoint that can be used to monitor pubsub events delivery statuses, it can be used like this: host:port/pubsub/history?startDate=2022-01-01T22:00:00&endDate=2022-01-13T23:59:00. When blocks are failing to be added/removed, are there any events with "state": "REJECTED"? Holly Mistlebauer Thanks, I'm checking the logs on Kiwi. Unfortunately, it doesn't look exactly like the problem that Cornell is reporting, which leaves a lot of options. These two can be bugs, or they can both be an issue with environments/configuration that doesn't need any code changes, or they can be two absolutely different things, e.g. one is a bug and another is an infrastructure issue. |
| Comment by Alexander Kurash [ 14/Jan/22 ] |
|
Holly Mistlebauer I think I'm close to finding the root cause of the issue you discovered on Kiwi. There are two events that make us mark an open loan as "lost" on mod-patron-blocks side - it's "declared lost" and "aged to lost". And there is only one event that can reverse this - "claimed returned". From mod-patron-blocks perspective, renewal just changes the due date but the loans stay open and "lost", so it doesn't affect the "Maximum number of lost items" block. |
| Comment by Stephanie Buck [ 18/Jan/22 ] |
|
Thomas Trutt, any chance we can get the logs (without patron data) as discussed above? Holly Mistlebauer, the issue you've found in Kiwi sounds like a separate issue. Can you file a separate bug please? It seems like this functionality wasn't implemented initially for Kiwi, but the stories were closed. |
| Comment by Thomas Trutt [ 18/Jan/22 ] |
|
Hi Stephanie Buck we are hosted so I do believe we have access to those logs. Anya is this something you can still get for the devs? if the logs need to be cleaned up you can send them to me and I can remove patron information. |
| Comment by Anya [ 18/Jan/22 ] |
|
Thomas Trutt I will request it - is there a day/time we should look for?
|
| Comment by Thomas Trutt [ 18/Jan/22 ] |
|
Thanks Anya . January 6th @10:40am |
| Comment by Anya [ 18/Jan/22 ] |
|
Thomas Trutt I have made the request. |
| Comment by David Bottorff [ 18/Jan/22 ] |
|
This is now impacting Chicag in juniper production. Is there a workaround for this? |
| Comment by Anya [ 18/Jan/22 ] |
|
There is no workaround. |
| Comment by David Bottorff [ 18/Jan/22 ] |
|
Timeline for a hot fix? |
| Comment by Alexander Kurash [ 19/Jan/22 ] |
|
David Bottorff Do you mean that 'Maximum fine/fee' stays in place? We still can't reproduce this bug on bugfest yet. This means that the code that calculates the blocks is working properly, but there can be issues with event delivery through pubsub/kafka on a particular environment which may require a bugfix in pubsub (or it may not require it if the issue is related to infrastructure, misconfiguration etc.). To find out we need to have a closer look at the logs (refer to conversation above). Another issue, found by Holly Mistlebauer, when 'Maximum number lost items' stays in place after renewal, is different one - looks like this functionality just wasn't ever implemented, so it should reproduce on any environment. This should be a separate ticket and probably a story. |
| Comment by David Bottorff [ 19/Jan/22 ] |
|
It is the maximum fee/fine block that remains in place: “Patron owes $50.00 or more in fees and fines” in Chicago’s test environment, Cheryl Malmborg reports that this seems to be related to the number of total loans on a patron account. The more loans the patron has in total, the more likely that the automated block will remain in place. |
| Comment by Holly Mistlebauer [ 19/Jan/22 ] |
|
Alexander Kurash: I don't see my issue as different from what was originally reported given the Summary of this ticket is Juniper: automatic blocks are not removed after renewed. What I am reporting is a block that isn't cleared after renewal. It just happens to be a different automated block from what was reported. Should we update this ticket Summary to Juniper: automatic block "Maximum Fee/Fine Balance" not removed after renewed when patron has more than X loans? Then I could make a ticket called Kiwi: automatic block "Maximum Lost Items" not removed after lost item renewed for what I found. Does this make sense? Thanks... |
| Comment by Holly Mistlebauer [ 19/Jan/22 ] |
|
David Bottorff and Cheryl Malmborg: How many loans should we test with? I would really like to reproduce this error on a Bugfest instance. |
| Comment by Holly Mistlebauer [ 19/Jan/22 ] |
|
Alexander Kurash: I'll just go ahead and make the changes in JIRA. They make sense. |
| Comment by Holly Mistlebauer [ 19/Jan/22 ] |
|
Alexander Kurash: I have created
|
| Comment by David Bottorff [ 19/Jan/22 ] |
|
Holly Mistlebauer It seems to kick in more consistently for patrons with 100 loaned items or more. Even when there is only 1 aged to lost item that is renewed |
| Comment by David Bottorff [ 19/Jan/22 ] |
|
We are also seeing this behavior when lost items are checked in at Chicago in production, so there may be more going on in our installation, given that I don't believe that behavior was reported at Cornell |
| Comment by Cheryl Malmborg [ 19/Jan/22 ] |
|
Holly Mistlebauer Testing last night on our indexdata test box, blocks were removed from patrons with 1, 4, 22, and 48 total loans. Blocks were not removed from 2 patrons with about 160 loans. I can try to find patrons with between 50 and 100 loans with only a few aged to lost to test. I need to query the OLE loans. I would try testing in bugfest with 100 loans with 3 aged to lost first. I am not convinced the behavior is consistent. The Cornell screen shot looked like the patron had only 10 loans. David just reported the a max amt owed block wasn't lifted when an aged to lost item was RETURNED. The patron has 67 loans, 1 aged to lost returned. I'm creating a new jira. |
| Comment by Alexander Kurash [ 20/Jan/22 ] |
|
Cheryl Malmborg David Bottorff Thomas Trutt Anya Holly Mistlebauer I'm gong to try to make list all issues we have at the moment, please correct me if I miss anything.
In my opinion, 1 and 2 have the same root cause - some of the FEE_FINE_BALANCE_CHANGE messages are not delivered from mod-feesfines to mod-patron-blocks for some reason. This would explain why it only happens sometimes and cannot be reproduced on other envs. It can be a pub-sub or Kafka issue and it can possibly affect other blocks. The fact that it happens after renewal in one case and after check-in in another case is, most probably, insignificant. Please check my comment in
3 is a different thing. It was found on Kiwi, but it should also reproduce on Juniper, Iris and all other releases since automated patron blocks implementation. And it should reproduce every time, it's not related to message delivery - it's just not implemented. As I said before, I'm not even sure it should be treated as a bug and not a change request because I can't find the original requirements saying that renewal should cancel the effect of Aged To Lost and Declared Lost actions on the 'Max number of lost items' block. I have found a conversation in the comments of a bug ticket though (
|
| Comment by Thomas Trutt [ 20/Jan/22 ] |
|
David Bottorff the 'workaround' that we have identified is not to renew the items. Check them in and back out; this will clear the fines correctly and clear all the blocks.. If the items were renewed it's stuck. Even removing the items from the patron's accounts does not remove the maximum fine block. I'm going to see if there is something i can do via the API but I haven't had time to try yet. Edit: I wrote the above before I was able to catch up on all the comments. I see your issue is that blocks are not being removed on check-in as well. So far we have not seen this issue only on renewals.
Side note I have been meaning to mention. I noticed on the patron open loan screen there is a fine listed even though it was canceled by the renewal. I will look over the steps you outlined Alexander and see if I can re-set the two account that we currently know of at Cornell. |
| Comment by Wayne Schneider [ 20/Jan/22 ] |
|
We are working on trying to reproduce this (for UChicago) somewhat reliably on a test system. On the system where we are experiencing the issue, interestingly enough, I found in the log where the events were processed, but the user summary was apparently not updated, though there are no errors that I can see (log attached block-not-cleared.log The user summary for that user (before running the sync API) looks like this:
{
"id": "14c48be3-b2ae-4baf-839b-3600dc8dc825",
"_version": 1,
"userId": "b2d4e001-49dd-43fc-ac1b-481e217fabb5",
"openLoans": [
{
"loanId": "1da974b5-c3ad-53a1-93c3-1c19b09ddf3b",
"dueDate": "2022-01-25T05:59:00.000+00:00",
"recall": false,
"itemLost": true,
"itemClaimedReturned": false
}
],
"openFeesFines": [
{
"feeFineId": "600354e8-bc75-4b67-b999-f25490da2969",
"feeFineTypeId": "cf238f9f-7018-47b7-b815-bb2db798e19f",
"loanId": "1da974b5-c3ad-53a1-93c3-1c19b09ddf3b",
"balance": 150.0
}
]
}
But in the UI the user shows no open fees/fines and 164 open loans. After running the sync job, the summary is set to "_version": 2 and the response shows all the open loans and no open fee/fines. In the UI, the block is cleared. I wonder if this is an artifact of the migration (as suggested by Cheryl Malmborg). It may make sense for us to the the full sync as suggested on
By the by, we are also seeing in the log a number of errors like this:
06:14:42 [] [] [] [] ERROR UserSummaryService { "message": "Cannot update record b473fba9-31b6-4de1-b5f4-14d40b9d82be because it has been changed (optimistic locking): Stored _version is 454, _version of request is 453", "severity": "ERROR", "code": "23F09", "where": "PL/pgSQL function user_summary_set_ol_version() line 8 at RAISE\nSQL statement \"UPDATE uchicago_mod_patron_blocks.user_summary SET jsonb=$3 WHERE id=$2 RETURNING id\"\nPL/pgSQL function upsert(text,uuid,anyelement) line 5 at EXECUTE", "file": "pl_exec.c", "line": "3855", "routine": "exec_stmt_raise", "schema": "uchicago_mod_patron_blocks", "table": "user_summary" }
...but it does look like it sensibly tries again (and succeeds), so I think that is unrelated. |
| Comment by Alexander Kurash [ 21/Jan/22 ] |
If some loan or fee/fine data was loaded to the DB bypassing our usual API calls to mod-circulation and mod-feesfines, it's actually required to run a full sync. Otherwise, this data will never be synchronized.
Yes, there's a retry mechanism. Version conflicts may happen from time to time, it's ok as long as updates succeed after a retry (or few retries). |
| Comment by Thomas Trutt [ 21/Jan/22 ] |
|
Alexander Kurash I am attaching a new json file for the patron that has a fine fee block on their account (folio-1642774002901.json). I followed the steps outlined in https://folio-org.atlassian.net/browse/MODPATBLK-112 for syncing a single user but it did not work. This is what was submitted and what was returned:
POST /automated-patron-blocks/synchronization/job body JSON:
{
"scope": "user",
"userId": "04ba8ffa-e761-4bf0-813c-31c0c31ca1b3"
}
Response JSON: {
"id": "a09c27d4-fea9-4112-bd17-9aced98fe0ef",
"scope": "user",
"status": "open",
"errors": [
]
}
Here is are the two fines listed as still open: {
"amount": 150.0,
"remaining": 0.0,
"status": {
"name": "Closed"
},
"paymentStatus": {
"name": "Cancelled item renewed"
},
"feeFineType": "Lost item fee",
"feeFineOwner": "Mann",
"title": "__REMOVED__",
"callNumber": "__REMOVED__"",
"barcode": "__REMOVED__"",
"location": "Mann",
"metadata": {
"createdDate": "2022-01-05T05:46:57.638+00:00",
"updatedDate": "2022-01-06T15:40:35.969+00:00",
"updatedByUserId": "7aa1d6fd-a09b-4b28-8629-89db597fd0cb"
},
"dueDate": "2021-12-09T04:59:59.000+00:00",
"loanId": "fb191589-c296-4922-949a-862e7ac18af4",
"userId": "04ba8ffa-e761-4bf0-813c-31c0c31ca1b3",
"itemId": "e4ec67e3-cf7c-4dce-bb4a-8c2e0db21224",
"materialTypeId": "1a54b431-2e4f-452d-9cae-9cee66c9a892",
"feeFineId": "cf238f9f-7018-47b7-b815-bb2db798e19f",
"ownerId": "692f1f0b-0e78-4e0b-8a41-8ccec1eb5f3e",
"id": "15f5449c-6c64-4c9b-93f2-4bdc58ae0be3",
"holdingsRecordId": "8b87b0ad-b452-45e4-84fe-27374f5ccf31",
"instanceId": "bc5f74a6-f39d-4cb9-b686-b9d51172a897"
}
{
"amount": 150.0,
"remaining": 0.0,
"status": {
"name": "Closed"
},
"paymentStatus": {
"name": "Cancelled item renewed"
},
"feeFineType": "Lost item fee",
"feeFineOwner": "Mann",
"title": "__REMOVED__"",
"callNumber": "__REMOVED__"",
"barcode": "__REMOVED__"",
"location": "Mann",
"metadata": {
"createdDate": "2022-01-05T05:46:57.640+00:00",
"updatedDate": "2022-01-06T15:40:35.978+00:00",
"updatedByUserId": "7aa1d6fd-a09b-4b28-8629-89db597fd0cb"
},
"dueDate": "2021-12-09T04:59:59.000+00:00",
"loanId": "343366b0-8bd7-4465-b005-99f06c1c1fa6",
"userId": "04ba8ffa-e761-4bf0-813c-31c0c31ca1b3",
"itemId": "de8ec6d7-e972-449a-9aa6-f6de94fba437",
"materialTypeId": "1a54b431-2e4f-452d-9cae-9cee66c9a892",
"feeFineId": "cf238f9f-7018-47b7-b815-bb2db798e19f",
"ownerId": "692f1f0b-0e78-4e0b-8a41-8ccec1eb5f3e",
"id": "a47f723c-7b7e-4a60-b8ed-f1b15bbadade",
"holdingsRecordId": "6acabd7e-9ea9-4e64-9982-4bfec3da1e78",
"instanceId": "e4b5d06c-f42a-4208-ad4d-9480fe67085a"
}
|
| Comment by Alexander Kurash [ 21/Jan/22 ] |
|
Thomas Trutt You can use Job ID (a09c27d4-fea9-4112-bd17-9aced98fe0ef) to make GET calls to /automated-patron-blocks/synchronization/job/JOB_ID to find out it's status, how many records were processed, were there any errors etc. Synchronization is done asynchronously so this information updates over time. So, these two fines (15f5449c-6c64-4c9b-93f2-4bdc58ae0be3 and a47f723c-7b7e-4a60-b8ed-f1b15bbadade) were listed in the UserSummary->openFeesFines of a user 04ba8ffa-e761-4bf0-813c-31c0c31ca1b3 even after running a sync on it? First, I would make sure that this sync was successful with the help of a GET endpoint above. Also, I'd want to have a closer look at this user's UserSummary object, can you please post it? It's GET /user-summary/userId. |
| Comment by Thomas Trutt [ 21/Jan/22 ] |
|
Alexander Kurash you are correct. The two fines were still listed as open even after running the job. Here is the response from /automated-patron-blocks/synchronization/job/a09c27d4-fea9-4112-bd17-9aced98fe0ef .
{
"id": "a09c27d4-fea9-4112-bd17-9aced98fe0ef",
"scope": "user",
"userId": "04ba8ffa-e761-4bf0-813c-31c0c31ca1b3",
"status": "done", "totalNumberOfLoans": 0,
"totalNumberOfFeesFines": 0,
"numberOfProcessedLoans": 10,
"numberOfProcessedFeesFines": 0,
"errors": [
]
}
I just re-checked user-summary , the `openFeesFines' key is now empty, but in the UI she is still blocked. Now it's the maximum number of lost items instead of maximum fines. (nothing is overdue) I'm attaching the new output from user-summary (folio-1642774002901 - New.Json) Im tagging Debra Howell. We just had an issue at ~11:10am with system slowdown, I believe loan-storage. I ran the job at 9:10am. I just want to ensure they are not related. |
| Comment by Alexander Kurash [ 24/Jan/22 ] |
But maybe they should be blocked because this patron just has a lot of lost items? In the JSON of the user summary you provided (after-the-sync version) there are 7 loans marked "lost":
Are they not really lost? Should we take a look at some of these loans and items? And what is the Maximum number of lost items limit set to? |
| Comment by Alexander Kurash [ 26/Jan/22 ] |
|
Thomas Trutt Is there any news? I noticed that at least some of these new open loans that we see in the new UserSummary (after synchronization) were not there before. So, can we take a look at them? Also, it would be interesting to know how these loans were created - was this a normal check-out process (which means that events from mod-circulation didn't reach mod-patron-blocks for some reason) or some kind of data import? Anya Thomas Trutt Holly Mistlebauer Stephanie Buck This is a P1 bug and a HotFix requested for it, but at the moment we basically know nothing except the fact that at some point for some reason mod-patron-blocks data went out of sync with mod-circulation-storage and mod-feesfines data. Potential reasons are:
As you can see, without knowing what happened with the data and why it went out of sync it'll be hard to say if we even need to fix something in the code of any module (and release a HotFix) or not. And we actually might never find out. So the question is should we in scope of this ticket concentrate on a workaround that would put data back in sync, which should fix immediate problems with patron blocks, and then see if it keeps working from this point on? It's not a code change and there will be no HotFix for it, but it should be done anyway because even if we find the reason why it went out of sync and it turns out to be a fixable-in-code thing, the fix sill won't put data back in sync, it would just stop it from getting worse. |
| Comment by Stephanie Buck [ 26/Jan/22 ] |
|
Thank you for the update, Alexander Kurash. I think we should focus on a workaround to get everything back in sync, and then create a separate ticket for investigating further the how and why we got here. Anya, Thomas Trutt and Holly Mistlebauer - please let us know if you disagree. |
| Comment by Thomas Trutt [ 28/Jan/22 ] |
|
Alexander Kurash Sorry i will get looking at this for you today and report back, ASAP.
|
| Comment by Thomas Trutt [ 28/Jan/22 ] |
|
Alexander Kurash So of the 17 loans listed only 10 of them are open. The other 7 that have the fines and are marked as lost are all closed. I will attach a dump of `/circulation/loans?query=(userId==04ba8ffa-e761-4bf0-813c-31c0c31ca1b3)%20sortby%20id&limit=2000` . I actually cehceked-in these 7 items in the hopes that it would clear the block on the patron's account. Anya got me the logs from when the renews were processed two days ago which though and remove any patron info and post those today as well. |
| Comment by Thomas Trutt [ 28/Jan/22 ] |
|
Alexander Kurash I added the dump from the API and the logs now.. In the mod-patorn-blocks log, I am seeing this error related to the user in question. 2022-01-06T15:40:36.331Z 15:40:36 [] [] [] [] ERROR UserSummaryService Failed to update user summary due to version conflict. User ID: 04ba8ffa-e761-4bf0-813c-31c0c31ca1b3. Attempt # 5 2022-01-06T15:40:36.331Z 15:40:36 [] [] [] [] INFO CQLWrapper CRITERION >>> SQL: WHERE (jsonb->>'userId') = '04ba8ffa-e761-4bf0-813c-31c0c31ca1b3' >>>WHERE (jsonb->>'userId') = '04ba8ffa-e761-4bf0-813c-31c0c31ca1b3' 2022-01-06T15:40:36.387Z 15:40:36 [] [] [] [] INFO EventHandler Event LOAN_DUE_DATE_CHANGED processed successfully. Affected user summary: c4a78967-7df3-4848-b667-09b8ffabcd95 2022-01-06T15:40:36.387Z 15:40:36 [] [] [] [] ERROR UserSummaryService { "message": "Cannot update record c4a78967-7df3-4848-b667-09b8ffabcd95 because it has been changed (optimistic locking): Stored _version is 23, _version of request is 22", "severity": "ERROR", "code": "23F09", "where": "PL/pgSQL function user_summary_set_ol_version() line 8 at RAISE\nSQL statement \"UPDATE fs00001034_mod_patron_blocks.user_summary SET jsonb=$3 WHERE id=$2 RETURNING id\"\nPL/pgSQL function upsert(text,uuid,anyelement) line 5 at EXECUTE", "file": "pl_exec.c", "line": "3855", "routine": "exec_stmt_raise", "schema": "fs00001034_mod_patron_blocks", "table": "user_summary" } 2022-01-06T15:40:36.387Z 15:40:36 [] [] [] [] ERROR UserSummaryService Failed to update user summary due to version conflict. User ID: 04ba8ffa-e761-4bf0-813c-31c0c31ca1b3. Attempt # 6 2022-01-06T15:40:36.387Z 15:40:36 [] [] [] [] INFO CQLWrapper CRITERION >>> SQL: WHERE (jsonb->>'userId') = '04ba8ffa-e761-4bf0-813c-31c0c31ca1b3' >>>WHERE (jsonb->>'userId') = '04ba8ffa-e761-4bf0-813c-31c0c31ca1b3' 2022-01-06T15:40:36.441Z 15:40:36 [] [] [] [] INFO EventHandler Event FEE_FINE_BALANCE_CHANGED processed successfully. Affected user summary: c4a78967-7df3-4848-b667-09b8ffabcd95 2022-01-06T15:40:54.842Z 15:40:54 [] [] [] [] INFO RestRouting invoking getAdminHealth It looks as if the user summary could not be updated by the Automated blocks process. |
| Comment by Alexander Kurash [ 28/Jan/22 ] |
|
Thomas Trutt Ok, first I need to understand what issue are we trying to solve. Were these loans closed before or after user summary in the attachment (with 7 "blocked" loans) was fetched? If those loans were really open at some point and "max number of lost items" limit was less than 7 for this patron group, then the patron was blocked correctly. Synchronization does't remove blocks, it just puts data back in sync so that blocks can be calculated correctly. When you checked in those lost items, what happened to the user summary and to the blocks?
|
| Comment by Alexander Kurash [ 28/Jan/22 ] |
Interesting.. Actually, there's nothing wrong with these logs - as you can see, it attempts to update it again and finally succeeds - "Event FEE_FINE_BALANCE_CHANGED processed successfully. ". If it really failed to update a user summary there would be something like "Failed to process event ... with payload: ..." in the logs. But what's alarming is that it took 6 attempts while maximum number of attempts is 10, so it was very close to failing. It looks as if at that moment fees/fines for this patron were created/paid/closed etc. many times for a very short period of time, causing version conflicts. BTW, do you know how many instances of mod-patron-blocks Cornell's env runs? Another possibility is that synchronization ran at this moment (2022-01-06T15:40:54) and some events kept going in on top of it. You can check it in the database, all sync jobs are stored in synchronization_jobs table. |
| Comment by Thomas Trutt [ 28/Jan/22 ] |
|
Anya would you happen to be able to answer Alexander Kurash questions? Since we are on a hosted environment I honestly have no idea how many instances of mod-patron-blocks is running. Anya is it also possible to pull the records from the synchronization_jobs table for 01-06-2022 around 3:40pm system time? Many thanks.. Sorry I did miss that it did actually succeed. I was scanning over the log to remove patron data and the block of errors stuck out, I admit I didn't continue reading. To your first question. I am 95% sure the user summery i uploaded was pulled after the 7 lost items where checked in and then back out to the patron. That said i just re-run /user-summary/04ba8ffa-e761-4bf0-813c-31c0c31ca1b3 call and am receive the same information as i posted before - 7 lost items and 10 items that are normal. All the lost items returned in user-summary are showing as closed in the ui and via /circulation/loans . |
| Comment by Thomas Trutt [ 31/Jan/22 ] |
|
Alexander Kurash we just had a new occurrence of this just come up. This one is different in that instead of being a lost item it's a recall. It appears that a loan that had a recall on it is still counting against the patron's blocks. Like the case, we were discussing this morning the user summary is reporting 4 items on the patron's account when there are only 3 open loans on the patron's account. I can upload the user-summary as well as the loan summary if that would help. |
| Comment by Wayne Schneider [ 31/Jan/22 ] |
|
We are seeing regular occurrences of this problem with some variations (fees resolved via renewing loans; fees resolved via waiving, etc.) for both UChicago and for Spokane Public Library. I'm not clear exactly what information would help you tracking this down. It's a little difficult to catch a failure as it occurs, as these are live and fairly busy systems. But I think it is pretty clear that, even when mod-pubsub is working in the general case, there are some issues with either event delivery or processing for mod-patron-blocks. |
| Comment by Alexander Kurash [ 01/Feb/22 ] |
|
Thomas Trutt I found a bug in the synchronization process. It only affects items that were aged to lost. I've created
|
| Comment by Thomas Trutt [ 01/Feb/22 ] |
|
Hi Alexander Kurash Thank you for the workaround, please note my previous comment though. We had the same issue happen with a recalled item. Here is the user-summary:
{
"id": "888248df-7f32-425f-8ac2-ddb28881b953",
"_version": 13,
"userId": "5e5e1279-26b1-4dc3-8643-a2a30faf60fd",
"openLoans": [
{
"loanId": "5e0f595f-af72-4b52-9546-0ce91c9eb48b",
"dueDate": "2022-11-20T04:59:59.000+00:00",
"recall": false,
"itemLost": false,
"itemClaimedReturned": false
}, {
"loanId": "ffbd13f5-3e37-4b48-9f97-117dc6ad77e6",
"dueDate": "2022-03-17T03:59:59.000+00:00",
"recall": false,
"itemLost": false, "itemClaimedReturned": false
}, {
"loanId": "afc2465e-3679-48da-b32e-c914fbcc3760", "dueDate":
"2022-01-26T04:59:59.000+00:00",
"recall": true,
"itemLost": false,
"itemClaimedReturned": false
}, {
"loanId": "09b2055e-0eac-4b90-b998-efdb5c1d8cbe",
"dueDate": "2022-02-15T04:59:59.000+00:00",
"recall": false,
"itemLost": false,
"itemClaimedReturned": false
}],
"openFeesFines": [ ]
}
Item 3 is closed and according to the loan, the record was returned before the due date. /loan-storage/loans/afc2465e-3679-48da-b32e-c914fbcc3760
{
"id": "afc2465e-3679-48da-b32e-c914fbcc3760",
"itemId": "986f5b55-be0d-4cbe-a71e-752d8ac09ad6",
"itemEffectiveLocationIdAtCheckOut": "f21f837e-214b-4eb9-9e40-06547c93f371",
"status": {
"name": "Closed"
},
"loanDate": "2021-12-20T19:57:34Z",
"dueDate": "2022-01-26T04:59:59.000+00:00",
"returnDate": "2022-01-15T21:12:11.000Z",
"systemReturnDate": "2022-01-15T21:12:11.590+00:00",
"action": "checkedin",
"itemStatus": "In transit",
"loanPolicyId": "fa831826-c7bb-41cb-855f-e2a2daab3859",
"checkoutServicePointId": "86932cca-3b71-4d29-b0e9-0680b1fffabf",
"checkinServicePointId": "86932cca-3b71-4d29-b0e9-0680b1fffabf",
"patronGroupIdAtCheckout": "3684a786-6671-4268-8ed0-9db82ebca60b",
"dueDateChangedByRecall": true,
"overdueFinePolicyId": "4bc9fec8-3dc3-4d06-92c4-502ebe22edf5",
"lostItemPolicyId": "81ba84ea-e272-44a3-9219-bf9593df1e78",
"metadata": {
"createdDate": "2021-12-20T19:57:34.775+00:00",
"createdByUserId": "22880f71-8362-4a48-bd01-d41a4a3b2189",
"updatedDate": "2022-01-15T21:12:12.129+00:00",
"updatedByUserId": "f37e852e-a91d-40f5-9c8e-994ce6ffe050"
}
}
|
| Comment by Alexander Kurash [ 02/Feb/22 ] |
|
Thomas Trutt I assume that you tried to run synchronization for this patron and it didn't work, meaning openLoan with loanId afc2465e-3679-48da-b32e-c914fbcc3760 didn't go away? If that's the case, this can be another (or probably the same) bug in the synchronization mechanism. If it's not the case, then it's just another example of data going out of sync and we can try to trace it back. In any case, can you please fetch all event that are related to this loan from mod-patron-blocks database with these queries:
SELECT * FROM {schema}.item_checked_out_event WHERE jsonb->>'loanId'='afc2465e-3679-48da-b32e-c914fbcc3760';
SELECT * FROM {schema}.item_claimed_returned_event WHERE jsonb->>'loanId'='afc2465e-3679-48da-b32e-c914fbcc3760';
SELECT * FROM {schema}.item_declared_lost_event WHERE jsonb->>'loanId'='afc2465e-3679-48da-b32e-c914fbcc3760';
SELECT * FROM {schema}.item_aged_to_lost_event WHERE jsonb->>'loanId'='afc2465e-3679-48da-b32e-c914fbcc3760';
SELECT * FROM {schema}.item_checked_in_event WHERE jsonb->>'loanId'='afc2465e-3679-48da-b32e-c914fbcc3760';
SELECT * FROM {schema}.loan_due_date_changed_event WHERE jsonb->>'loanId'='afc2465e-3679-48da-b32e-c914fbcc3760';
|
| Comment by Anya [ 03/Feb/22 ] |
|
Support: This is also impacting Massey University... Anton Emelianov could you please add Massey to the list of impacted institutions, Stephanie Buck FYI - cc Tim Darlington |
| Comment by Anne L. Highsmith [ 09/Feb/22 ] |
|
Hello, Alexander Kurash I tried the workaround workaround you described above in our development instance. count ------- delete from tamu_mod_patron_blocks.item_aged_to_lost_event where jsonb->>'userId' = '4c9c84ec-ab46-3ce9-8525-fedbab8ebfca'; But when I look at the user record, patron still has blocks for "exceeded maximum number of lost items" and "has exceeded maximum number of outstanding fee/fines allowed". Is there something else I need to do? We're getting complaints from users that they've renewed books and still have blocks, which is a real public service problem.
|
| Comment by Wayne Schneider [ 10/Feb/22 ] |
|
Anne L. Highsmith see the workaround documented in MODPATBLK-112. You can sync the summary for individual users or for all users. We've had success running the full synchronization nightly. Even on a large system, the full sync takes less than 5 minutes (it runs in the background). |
| Comment by Alexander Kurash [ 14/Feb/22 ] |
|
Anne L. Highsmith A workaround with deletion of "aged to lost" events was a workaround for an issue with synchronization not working properly for patrons with aged to lost items. I mean, by itself this deletion does nothing, it should be followed by running a synchronization process as Wayne Schneider suggested. If you're going to run a full sync, it makes sense to delete all records from item_aged_to_lost_event before running it. Thomas Trutt I have a question regarding situation with loan afc2465e-3679-48da-b32e-c914fbcc3760 that you mentioned in your latest message. I can't find a call to /circulation/check-in-by-barcode endpoint that should have closed this loan. I can see calls to storage that updated the record in the DB, but not to mod-circulation. Do you know if there are other ways of closing the loan, other that via /circulation/check-in-by-barcode endpoint? And how this particular loan was closed? |
| Comment by Thomas Trutt [ 14/Feb/22 ] |
|
Alexander Kurash I do not know of any other way the loan could have been closed. I will look over the record some more, to ensure nothing else happened to it. |
| Comment by Thomas Trutt [ 15/Feb/22 ] |
|
Alexander Kurash I looked some more at this and im not seeing a that would indicate that it may have been processed outside the normal channels. The item in question looks like it may have been recalled for reserves. From what I am seeing in the logs is that the item came back, was checked in by staff, held for 2-3 minutes then checked out to one of our SPEC cards. The only person running batch jobs is Jenn Colt but that is for LTS. |
| Comment by Jenn Colt [ 15/Feb/22 ] |
|
The metadata on the loan indicates it was last updated by a regular staff member at a unit library service point. I don't see any indication of anything unusual but that is just at the json level, not the db. |
| Comment by Thomas Trutt [ 15/Feb/22 ] |
|
Hi, Alexander Kurash is there an equivalent to the [tenant]_mod_patron_blocks.item_aged_to_lost_event that we can run to remove the recall block on the patron above. Or instead, would you suggest just emptying [tenant]_mod_patron_blocks and running a system-wide synchronization? thanks. |
| Comment by Alexander Kurash [ 16/Feb/22 ] |
|
Thomas Trutt Have you tried to run a synchronization for this particular patron? I know I already asked this, but you didn't answer. BTW, before running a sync, could you please save the events from the DB - I posted query examples on Feb 2. This should help with the investigation. After that, try to run it, then check patron's user summary again. This part should be gone:
, {
"loanId": "09b2055e-0eac-4b90-b998-efdb5c1d8cbe",
"dueDate": "2022-02-15T04:59:59.000+00:00",
"recall": false,
"itemLost": false,
"itemClaimedReturned": false
}
If it's gone, the block should be gone too. I would only consider any further actions if this doesn't work. Couple of things to consider:
|
| Comment by Alexander Kurash [ 16/Feb/22 ] |
|
Thomas Trutt Jenn Colt If this item was really checked in, can you please tell me the exact date and time, if possible? Did it happen around 2022-01-15 21:12:12 UTC? |
| Comment by Jenn Colt [ 16/Feb/22 ] |
|
It looks like it: "loanDate": "2021-12-20T19:57:34Z",
|
| Comment by Thomas Trutt [ 17/Feb/22 ] |
|
thanks, Jenn Colt I will pull the records and try a sync on this account for you later today, and post everything here if it is not cleared. to answer your question though no I have not tried to run the sync on this account as it did not work on the previous one, I will do so.
here is also a link to the RA-Sig conversation, posted by Anne L. Highsmith at TAMU, https://folio-project.slack.com/archives/C3G05TF3R/p1644958459539259. she mentioned that the resync was working for them but then stopped for one of the accounts and then started working again the next day. |
| Comment by Thomas Trutt [ 17/Feb/22 ] |
|
Alexander Kurash I ran the sync process for the user with the recall on their account, and it did clear the block. Thank you. I did save the JSON from each step in case you want them. |
| Comment by Alexander Kurash [ 21/Feb/22 ] |
|
Anya I guess we can't close this ticket because a lot of institutions faced with this out-of-sync data issue, but at the same time there's nothing specific we can investigate. I believe, all the issues mentioned in this ticket were fixed by running a synchronization. Do you have any ideas about how should we move forward? Maybe, specific cases or more examples of the issue? |
| Comment by Charlotte Whitt [ 21/Feb/22 ] |
|
Support SIG: This is very critical for the affected libraries. Are we still on the path for R2 2021 Hot Fix #7? |
| Comment by Charlotte Whitt [ 22/Feb/22 ] |
|
Holly Mistlebauer please see Alexander Kurash'a comment above. |
| Comment by Stephanie Buck [ 25/Feb/22 ] |
|
Hello all. I'm going to close this ticket next week. As Alexander Kurash notes above, the issues mentioned in this ticket were fixed by running a synchronization. I have added notes to the workaround section of this bug. cc: Anya, Jenn Colt, Thomas Trutt, Holly Mistlebauer, Charlotte Whitt |
| Comment by Thomas Trutt [ 25/Feb/22 ] |
|
Thanks Stephanie Buck.. It is also my understanding that the root cause of this issue has been addressed in Kiwi. If that is the case I have no issue closing the ticket. |
| Comment by Stephanie Buck [ 25/Feb/22 ] |
|
That's correct, Thomas Trutt. |
| Comment by Thomas Trutt [ 28/Feb/22 ] |
|
Stephanie Buck So I just tried to do a re-sync in Kiwi and the blocks are not clearing. I will contact our host about doing the extra step of clearing the data from the database. I wasn't sure if you would want to re-open this or not. |
| Comment by Stephanie Buck [ 28/Feb/22 ] |
|
Thank you, Thomas Trutt.
|
| Comment by Stephanie Buck [ 28/Feb/22 ] |
|
Please see workaround. |