Regression - Missing item reference causing patron action session to not expire
Description
CSP Request Details
CSP Rejection Details
Potential Workaround
clones
defines
has to be done before
is blocked by
Checklist
hideTestRail: Results
Activity
Alina DoroshJanuary 10, 2022 at 10:03 AM
Hello @Stephanie Buck!
Work as expected on the Snapshot env.
Stephanie BuckNovember 29, 2021 at 1:59 PM
Thank you, @Alexander Kurash. Go ahead and use this ticket as you've proposed above.
Alexander KurashNovember 22, 2021 at 10:55 AM
According to Vega's and FSE investigation, the issue is caused by missing patron group. When we try to send a notice, circulation rules are executed (to find a loan policy) and this execution throws NPE when patron group is missing. @Sobha Duvvuri resolved it on production env by assigning patron groups to all patrons that didn't have it. This situation needs to be handled better and I propose this ticket to serve this purpose.
Also, @Sobha Duvvuri mentioned that it looked like "broken" notices were stopping others from being delivered. Another ticket will be created to make sure it isn't happening.
Thomas TruttNovember 19, 2021 at 7:47 PM
This issue almost feels like it is more related to inventory instead of Circulation. I mention this because IMO a check should be made from the inventory app to ensure that there are no open loans, open requests, etc for an item before it is allowed to be deleted. As a related issue are closed circulation transactions that have pointers to null item records. This goes back to data synchronization where when an item is removed from inventory the pointers in the closed circulation records should also be updated to either update the record that the item was deleted or the records themselves be removed. If you feel this should be a separate issue please let me know and I can fill one out.
Sobha DuvvuriNovember 18, 2021 at 10:26 PMEdited
@Stephanie Buck: I did not try to reproduce the issue in Bugfest but we just had another occurrence for Cornell today where the timer call to expire patron sessions was failing due to a NullPointerException -
From logs -
INFO TenantManager timer call failed to module mod-circulation-20.1.7 for tenant fs00001034 : POST request for mod-circulation-20.1.7 /circulation/notice-session-expiration-by-timeout failed with 500: java.lang.NullPointerException
WARN ProxyService POST request for mod-circulation-20.1.7 /circulation/notice-session-expiration-by-timeout failed with 500: java.lang.NullPointerException
INFO OkapiClient 360414/circulation RES 500 318255us okapiClient http://pvt.lb.icnl.folio-eis.us-east-1:8051/mod-circulation/circulation/notice-session-expiration-by-timeout
POST /mod-circulation/circulation/notice-session-expiration-by-timeout HTTP/1.1" 500Observed that the loan did not have a corresponding item entry - deleted the stuck session and expired the remaining.
Just wanted to mention that we also saw similar behavior for scheduled-notices where failure to send one scheduled notice gets the others stuck and the failed ones were also due to NPE - Please see logs below -
11:54:48 ERROR heduledNoticeHandler Data collection for scheduled notice bc28d742-1f8b-4d01-a16e-57c81a865e76 failed: Server error failure, reason: java.lang.NullPointerException
2021-11-18T13:54:48.937+02:00 java.lang.NullPointerException
2021-11-18T13:54:48.937+02:00 at java.base/java.util.Objects.requireNonNull(Objects.java:221)
2021-11-18T13:54:48.937+02:00 at io.vertx.core.http.CaseInsensitiveHeaders.add(CaseInsensitiveHeaders.java:119)
2021-11-18T13:54:48.937+02:00 at org.folio.circulation.rules.RulesExecutionParameters.toMap(RulesExecutionParameters.java:35)
2021-11-18T13:54:48.937+02:00 at org.folio.circulation.rules.ExecutableRules.lambda$determinePolicy$0(ExecutableRules.java:61)
2021-11-18T13:54:48.937+02:00 at org.folio.circulation.support.results.Result.of(Result.java:30)
2021-11-18T13:54:48.937+02:00 at org.folio.circulation.rules.ExecutableRules.determinePolicy(ExecutableRules.java:61)
2021-11-18T13:54:48.937+02:00 at org.folio.circulation.rules.ExecutableRules.determineLoanPolicy(ExecutableRules.java:34)
2021-11-18T13:54:48.937+02:00 at org.folio.circulation.rules.CirculationRulesProcessor.lambda$executeRules$6(CirculationRulesProcessor.java:114)
2021-11-18T13:54:48.937+02:00 at org.folio.circulation.support.results.Result.lambda$combineToResult$4(Result.java:107)
2021-11-18T13:54:48.937+02:00 at org.folio.circulation.support.results.Result.next(Result.java:274)
2021-11-18T13:54:48.937+02:00 at org.folio.circulation.support.results.Result.lambda$combineToResult$5(Result.java:106)
2021-11-18T13:54:48.937+02:00 at org.folio.circulation.support.results.Result.next(Result.java:274)
2021-11-18T13:54:48.937+02:00 at org.folio.circulation.support.results.Result.combineToResult(Result.java:105)
2021-11-18T13:54:48.937+02:00 at org.folio.circulation.support.results.Result.lambda$combined$16(Result.java:344)
2021-11-18T13:54:48.937+02:00 at java.base/java.util.concurrent.CompletableFuture.biApply(CompletableFuture.java:1236)
2021-11-18T13:54:48.937+02:00 at java.base/java.util.concurrent.CompletableFuture$BiApply.tryFire(CompletableFuture.java:1205)
2021-11-18T13:54:48.937+02:00 at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
2021-11-18T13:54:48.937+02:00 at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2073)
2021-11-18T13:54:48.937+02:00 at io.vertx.ext.web.client.impl.HttpContext.handleDispatchResponse(HttpContext.java:310)
2021-11-18T13:54:48.937+02:00 at io.vertx.ext.web.client.impl.HttpContext.execute(HttpContext.java:297)
2021-11-18T13:54:48.937+02:00 at io.vertx.ext.web.client.impl.HttpContext.next(HttpContext.java:272)
2021-11-18T13:54:48.937+02:00 at io.vertx.ext.web.client.impl.predicate.PredicateInterceptor.handle(PredicateInterceptor.java:69)
2021-11-18T13:54:48.937+02:00 at io.vertx.ext.web.client.impl.predicate.PredicateInterceptor.handle(PredicateInterceptor.java:32)
2021-11-18T13:54:48.937+02:00 at io.vertx.ext.web.client.impl.HttpContext.next(HttpContext.java:269)
2021-11-18T13:54:48.937+02:00 at io.vertx.ext.web.client.impl.HttpContext.fire(HttpContext.java:279)
2021-11-18T13:54:48.937+02:00 at io.vertx.ext.web.client.impl.HttpContext.dispatchResponse(HttpContext.java:240)
2021-11-18T13:54:48.937+02:00 at io.vertx.ext.web.client.impl.HttpContext.lambda$null$2(HttpContext.java:370)
2021-11-18T13:54:48.937+02:00 at io.vertx.core.impl.ContextImpl.executeTask(ContextImpl.java:366)
2021-11-18T13:54:48.937+02:00 at io.vertx.core.impl.WorkerContext.lambda$wrapTask$0(WorkerContext.java:35)
2021-11-18T13:54:48.937+02:00 at io.vertx.core.impl.TaskQueue.run(TaskQueue.java:76)
2021-11-18T13:54:48.937+02:00 at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2021-11-18T13:54:48.937+02:00 at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2021-11-18T13:54:48.937+02:00 at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
2021-11-18T13:54:48.937+02:00 at java.base/java.lang.Thread.run(Thread.java:829)
2021-11-18T13:54:48.937+02:00 11:54:48 ERROR heduledNoticeHandler Failed to collect data for 4 of 4 scheduled "Due date" non-real-time notices
Details
Assignee
Sherzod NurjonovSherzod NurjonovReporter
Stephanie BuckStephanie BuckPriority
P3Story Points
3Sprint
NoneDevelopment Team
VegaParent
Fix versions
Release
Lotus R1 2022RCA Group
Legitimate regressionAffected Institution
CaltechChalmersCornellTestRail: Cases
Open TestRail: CasesTestRail: Runs
Open TestRail: Runs
Details
Details
Assignee
Reporter
Priority
P3
This is a cloned description from an earlier bug that has reappeared.
Overview:
Observed Chalmers Patron Action Session timer task cannot expire a Session due to Session's associated loan referencing a non-existing item
Steps to Reproduce:
Log into FOLIO environment
Check in an item but do not click End Session
Observed item was damaged, go to Inventory and delete the item
Expected Results:
Patron Action Session Can be expired by timer task
Actual Results:
Patron Action Session cannot be expired and NPE is observed in mod-circulation logs
Additional Information:
1600401473299,03:57:53 WARN ProxyService POST request for mod-circulation-18.0.9 /circulation/notice-session-expiration-by-timeout failed with 500: java.lang.NullPointerException 1600401473299,java.lang.NullPointerException 1600401473299, at java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:193) 1600401473299, at java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1380) 1600401473299, at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:481) 1600401473299, at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:471) 1600401473299, at java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:708) 1600401473299, at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) 1600401473299, at java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:499) 1600401473299, at org.folio.circulation.domain.LocationRepository.getCampuses(LocationRepository.java:151) 1600401473299, at org.folio.circulation.domain.notice.session.PatronActionSessionRepository.fetchCampusesForLoanItems(PatronActionSessionRepository.java:175) 1600401473299, at org.folio.circulation.support.Result.after(Result.java:313) 1600401473299, at org.folio.circulation.domain.notice.session.PatronActionSessionRepository.lambda$fetchLoans$11(PatronActionSessionRepository.java:163) 1600401473299, at java.util.concurrent.CompletableFuture.uniCompose(CompletableFuture.java:952) 1600401473299, at java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:926) 1600401473299, at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474) 1600401473299, at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:1962) 1600401473299, at io.vertx.ext.web.client.impl.HttpContext.handleDispatchResponse(HttpContext.java:308) 1600401473299, at io.vertx.ext.web.client.impl.HttpContext.execute(HttpContext.java:295) 1600401473299, at io.vertx.ext.web.client.impl.HttpContext.next(HttpContext.java:270) 1600401473299, at io.vertx.ext.web.client.impl.predicate.PredicateInterceptor.handle(PredicateInterceptor.java:69) 1600401473299, at io.vertx.ext.web.client.impl.predicate.PredicateInterceptor.handle(PredicateInterceptor.java:32) 1600401473299, at io.vertx.ext.web.client.impl.HttpContext.next(HttpContext.java:267) 1600401473299, at io.vertx.ext.web.client.impl.HttpContext.fire(HttpContext.java:277) 1600401473299, at io.vertx.ext.web.client.impl.HttpContext.dispatchResponse(HttpContext.java:238) 1600401473299, at io.vertx.ext.web.client.impl.HttpContext.lambda$null$2(HttpContext.java:367) 1600401473299, at io.vertx.core.impl.ContextImpl.executeTask(ContextImpl.java:369) 1600401473299, at io.vertx.core.impl.WorkerContext.lambda$wrapTask$0(WorkerContext.java:35) 1600401473299, at io.vertx.core.impl.TaskQueue.run(TaskQueue.java:76) 1600401473299, at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) 1600401473299, at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) 1600401473299, at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) 1600401473299, at java.lang.Thread.run(Thread.java:748)URL:
Interested parties:
@Lisa Sjögren