NHibernate Redis Caches goes into closed loop with multiple threads
EngSayed opened this issue · 20 comments
EngSayed commented
I have multiple applications sharing the same backend code and after enabling SLC with Redis provider then application hangs in startup.
In the startup of each application it goes load thousands of data and tries to load/get from/into Redis. When I start 2 applications at the same moment then one manages to start while the second hangs and when I montiored Redis, I found that it keeps looping in getting a lot of keys over and over again.
This happens when Redis is empty and two applications would try to write the data into Redis. I have set cache.region_strategy.default.retry_times to 5 but no difference
Attached log file.
fredericDelaporte commented
Would you be able to reproduce the trouble with the NHibernate-Caches test project? It will confirm this is not specific to your application.
EngSayed commented
I found those lines in the end of Debug.log
2023-08-31 17:17:56,319 - executing flush
2023-08-31 17:17:56,320 - Registering flush begin
2023-08-31 17:17:56,324 - Putting 1 objects...
2023-08-31 17:17:56,324 - Putting object with key: '{NHibernate-Cache:UpdateTimestampsCache}-1:dbo.RequestException'.
2023-08-31 17:17:56,401 - Registering flush end
2023-08-31 17:17:56,404 - post flush
2023-08-31 17:17:56,412 - DbTransaction Committed
2023-08-31 17:17:56,413 - Transaction completed on session with on_close connection release mode; be sure to close the session to release ADO.Net resources!
2023-08-31 17:17:56,413 - transaction completion
2023-08-31 17:17:56,422 - Invalidating spaces [dbo.RequestException]
2023-08-31 17:17:56,422 - Putting 1 objects...
2023-08-31 17:17:56,422 - Putting object with key: '{NHibernate-Cache:UpdateTimestampsCache}-1:dbo.RequestException'.
2023-08-31 17:17:56,497 - DbTransaction disposed.
2023-08-31 17:17:56,526 - [session-id=b5dc4388-e930-4761-a070-c4d51bdfd359] running ISession.Dispose()
2023-08-31 17:17:56,526 - [session-id=b5dc4388-e930-4761-a070-c4d51bdfd359] executing real Dispose(True)
2023-08-31 17:17:56,527 - closing session
2023-08-31 17:17:56,528 - running BatcherImpl.Dispose(true)
2023-08-31 17:17:56,528 - Closing connection
Is this only SQL flush?
EngSayed commented
Would you be able to reproduce the trouble with the NHibernate-Caches test project? It will confirm this is not specific to your application.
Which test project?
Btw, how could it be specific to my application?
It works fine if I start one application at a time ... it fails when I try to start 2 applications at the same time. First application is ASP.NET MVC and the second is ASP.NET WEB API
EngSayed commented
@fredericDelaporte,
So I have enabled logging and done debugging ... here is what I found:
First, I have an entity class called Entity which has a relation bag (one-to-many) with class EntityRelationship. And EntityRelationship has a many-to-one relation with class LookupGroup.
So when I load all Entities and then load all associations of EntityRelationship then it loads LookupGroup
I observed that the issue happens with LookupGroup. So when a record of EntityRelationship with a reference to LookupGroup then it tries to GetMany (I have default_batch_fetch_size = 25) and instead of only loading one LookupGroup (let's assume id = 1) then it goes to BatchFetchQueue.GetEntityBatch which calculate 25 keys to load from Redis.
As you can see it it tries to fetch 25 keys from Redis which says that Cached item was locked but then it reports that the cache is missed for only one key Entity cache miss: Entities.LookupGroup#1:
2023-09-03 14:28:19,924 - **loading entity: [Entities.LookupGroup#1]**
2023-09-03 14:28:19,925 - attempting to resolve: [Entities.LookupGroup#1]
2023-09-03 14:28:19,972 - Cache lookup: Entities.LookupGroup#1,Entities.LookupGroup#2,Entities.LookupGroup#3,Entities.LookupGroup#4,Entities.LookupGroup#5,Entities.LookupGroup#6,Entities.LookupGroup#8,Entities.LookupGroup#9,Entities.LookupGroup#10,Entities.LookupGroup#7,Entities.LookupGroup#11,Entities.LookupGroup#12,Entities.LookupGroup#13,Entities.LookupGroup#14,Entities.LookupGroup#15,Entities.LookupGroup#16,Entities.LookupGroup#17,Entities.LookupGroup#18,Entities.LookupGroup#462,Entities.LookupGroup#19,Entities.LookupGroup#20,Entities.LookupGroup#21,Entities.LookupGroup#22,Entities.LookupGroup#23,Entities.LookupGroup#24
2023-09-03 14:28:19,977 - **Fetching 25 objects**...
2023-09-03 14:28:19,978 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#1'.
2023-09-03 14:28:19,978 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#2'.
2023-09-03 14:28:19,979 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#3'.
2023-09-03 14:28:19,979 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#4'.
2023-09-03 14:28:19,980 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#5'.
2023-09-03 14:28:19,980 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#6'.
2023-09-03 14:28:19,981 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#8'.
2023-09-03 14:28:19,982 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#9'.
2023-09-03 14:28:19,982 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#10'.
2023-09-03 14:28:19,983 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#7'.
2023-09-03 14:28:19,985 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#11'.
2023-09-03 14:28:19,986 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#12'.
2023-09-03 14:28:19,986 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#13'.
2023-09-03 14:28:19,987 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#14'.
2023-09-03 14:28:19,988 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#15'.
2023-09-03 14:28:19,989 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#16'.
2023-09-03 14:28:19,990 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#17'.
2023-09-03 14:28:19,991 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#18'.
2023-09-03 14:28:19,992 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#462'.
2023-09-03 14:28:19,993 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#19'.
2023-09-03 14:28:19,994 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#20'.
2023-09-03 14:28:19,994 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#21'.
2023-09-03 14:28:19,995 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#22'.
2023-09-03 14:28:19,995 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#23'.
2023-09-03 14:28:19,996 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#24'.
2023-09-03 14:28:20,414 - Cached item was locked: Entities.LookupGroup#1
2023-09-03 14:28:20,415 - Cached item was locked: Entities.LookupGroup#2
2023-09-03 14:28:20,416 - Cached item was locked: Entities.LookupGroup#3
2023-09-03 14:28:20,417 - Cached item was locked: Entities.LookupGroup#4
2023-09-03 14:28:20,417 - Cached item was locked: Entities.LookupGroup#5
2023-09-03 14:28:20,418 - Cached item was locked: Entities.LookupGroup#6
2023-09-03 14:28:20,419 - Cached item was locked: Entities.LookupGroup#8
2023-09-03 14:28:20,419 - Cached item was locked: Entities.LookupGroup#9
2023-09-03 14:28:20,420 - Cached item was locked: Entities.LookupGroup#10
2023-09-03 14:28:20,421 - Cached item was locked: Entities.LookupGroup#7
2023-09-03 14:28:20,421 - Cached item was locked: Entities.LookupGroup#11
2023-09-03 14:28:20,422 - Cached item was locked: Entities.LookupGroup#12
2023-09-03 14:28:20,423 - Cached item was locked: Entities.LookupGroup#13
2023-09-03 14:28:20,424 - Cached item was locked: Entities.LookupGroup#14
2023-09-03 14:28:20,426 - Cached item was locked: Entities.LookupGroup#15
2023-09-03 14:28:20,427 - Cached item was locked: Entities.LookupGroup#16
2023-09-03 14:28:20,429 - Cached item was locked: Entities.LookupGroup#17
2023-09-03 14:28:20,430 - Cached item was locked: Entities.LookupGroup#18
2023-09-03 14:28:20,430 - Cached item was locked: Entities.LookupGroup#462
2023-09-03 14:28:20,431 - Cached item was locked: Entities.LookupGroup#19
2023-09-03 14:28:20,432 - Cached item was locked: Entities.LookupGroup#20
2023-09-03 14:28:20,432 - Cached item was locked: Entities.LookupGroup#21
2023-09-03 14:28:20,433 - Cached item was locked: Entities.LookupGroup#22
2023-09-03 14:28:20,433 - Cached item was locked: Entities.LookupGroup#23
2023-09-03 14:28:20,434 - Cached item was locked: Entities.LookupGroup#24
2023-09-03 14:28:20,440 - **Entity cache miss: Entities.LookupGroup#1**
2023-09-03 14:28:20,441 - object not resolved in any cache: [Entities.LookupGroup#1]
2023-09-03 14:28:20,446 - Fetching entity: [Entities.LookupGroup#1]
2023-09-03 14:28:20,475 - Fetching 25 objects...
2023-09-03 14:28:20,476 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#2'.
2023-09-03 14:28:20,476 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#3'.
2023-09-03 14:28:20,477 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#4'.
2023-09-03 14:28:20,478 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#5'.
2023-09-03 14:28:20,478 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#6'.
2023-09-03 14:28:20,479 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#8'.
2023-09-03 14:28:20,480 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#9'.
2023-09-03 14:28:20,480 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#10'.
2023-09-03 14:28:20,481 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#7'.
2023-09-03 14:28:20,482 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#11'.
2023-09-03 14:28:20,483 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#12'.
2023-09-03 14:28:20,483 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#13'.
2023-09-03 14:28:20,484 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#14'.
2023-09-03 14:28:20,484 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#15'.
2023-09-03 14:28:20,485 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#16'.
2023-09-03 14:28:20,486 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#17'.
2023-09-03 14:28:20,486 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#18'.
2023-09-03 14:28:20,488 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#462'.
2023-09-03 14:28:20,488 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#19'.
2023-09-03 14:28:20,489 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#20'.
2023-09-03 14:28:20,490 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#21'.
2023-09-03 14:28:20,492 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#22'.
2023-09-03 14:28:20,493 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#23'.
2023-09-03 14:28:20,494 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#24'.
2023-09-03 14:28:20,495 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#27'.
After that for some weird reason it goes into fetching all rest of LookupGroup keys:
023-09-03 14:28:20,494 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#24'.
2023-09-03 14:28:20,495 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#27'.
2023-09-03 14:28:20,571 - Fetching 1 objects...
2023-09-03 14:28:20,572 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#28'.
2023-09-03 14:28:20,670 - Fetching 1 objects...
2023-09-03 14:28:20,671 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#29'.
2023-09-03 14:28:20,773 - Fetching 1 objects...
2023-09-03 14:28:20,774 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#30'.
2023-09-03 14:28:20,877 - Fetching 1 objects...
2023-09-03 14:28:20,877 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#31'.
2023-09-03 14:28:20,978 - Fetching 1 objects...
2023-09-03 14:28:20,978 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#32'.
2023-09-03 14:28:21,086 - Fetching 1 objects...
2023-09-03 14:28:21,087 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#33'.
2023-09-03 14:28:21,182 - Fetching 1 objects...
2023-09-03 14:28:21,183 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#34'.
2023-09-03 14:28:21,238 - Fetching 1 objects...
2023-09-03 14:28:21,238 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#35'.
2023-09-03 14:28:21,338 - Fetching 1 objects...
2023-09-03 14:28:21,339 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#36'.
2023-09-03 14:28:21,440 - Fetching 1 objects...
2023-09-03 14:28:21,441 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#37'.
2023-09-03 14:28:21,542 - Fetching 1 objects...
2023-09-03 14:28:21,543 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#38'.
2023-09-03 14:28:21,598 - Fetching 1 objects...
2023-09-03 14:28:21,599 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#39'.
2023-09-03 14:28:21,695 - Fetching 1 objects...
2023-09-03 14:28:21,697 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#40'.
2023-09-03 14:28:21,806 - Fetching 1 objects...
2023-09-03 14:28:21,807 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#41'.
2023-09-03 14:28:21,900 - Fetching 1 objects...
2023-09-03 14:28:21,901 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#42'.
2023-09-03 14:28:22,002 - Fetching 1 objects...
2023-09-03 14:28:22,003 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#43'.
2023-09-03 14:28:22,105 - Fetching 1 objects...
2023-09-03 14:28:22,106 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#44'.
2023-09-03 14:28:22,207 - Fetching 1 objects...
2023-09-03 14:28:22,208 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#45'.
2023-09-03 14:28:22,309 - Fetching 1 objects...
2023-09-03 14:28:22,310 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#46'.
2023-09-03 14:28:22,364 - Fetching 1 objects...
2023-09-03 14:28:22,365 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#47'.
2023-09-03 14:28:22,465 - Fetching 1 objects...
2023-09-03 14:28:22,465 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#48'.
2023-09-03 14:28:22,566 - Fetching 1 objects...
2023-09-03 14:28:22,567 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#49'.
2023-09-03 14:28:22,668 - Fetching 1 objects...
2023-09-03 14:28:22,669 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#50'.
2023-09-03 14:28:22,723 - Fetching 1 objects...
2023-09-03 14:28:22,724 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#51'.
2023-09-03 14:28:22,822 - Fetching 1 objects...
2023-09-03 14:28:22,823 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#52'.
2023-09-03 14:28:22,924 - Fetching 1 objects...
2023-09-03 14:28:22,924 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#53'.
2023-09-03 14:28:23,026 - Fetching 1 objects...
2023-09-03 14:28:23,027 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#54'.
2023-09-03 14:28:23,082 - Fetching 1 objects...
2023-09-03 14:28:23,082 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#55'.
2023-09-03 14:28:23,181 - Fetching 1 objects...
2023-09-03 14:28:23,181 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#56'.
2023-09-03 14:28:23,236 - Fetching 1 objects...
2023-09-03 14:28:23,237 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#57'.
2023-09-03 14:28:23,333 - Fetching 1 objects...
2023-09-03 14:28:23,334 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#58'.
2023-09-03 14:28:23,389 - Fetching 1 objects...
2023-09-03 14:28:23,390 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#59'.
2023-09-03 14:28:23,489 - Fetching 1 objects...
2023-09-03 14:28:23,490 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#60'.
2023-09-03 14:28:23,590 - Fetching 1 objects...
2023-09-03 14:28:23,591 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#61'.
2023-09-03 14:28:23,645 - Fetching 1 objects...
2023-09-03 14:28:23,646 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#62'.
2023-09-03 14:28:23,743 - Fetching 1 objects...
2023-09-03 14:28:23,744 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#63'.
2023-09-03 14:28:23,845 - Fetching 1 objects...
2023-09-03 14:28:23,846 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#64'.
2023-09-03 14:28:23,949 - Fetching 1 objects...
2023-09-03 14:28:23,949 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#65'.
2023-09-03 14:28:24,050 - Fetching 1 objects...
2023-09-03 14:28:24,051 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#66'.
2023-09-03 14:28:24,153 - Fetching 1 objects...
2023-09-03 14:28:24,154 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#67'.
2023-09-03 14:28:24,256 - Fetching 1 objects...
2023-09-03 14:28:24,256 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#68'.
2023-09-03 14:28:24,310 - Fetching 1 objects...
2023-09-03 14:28:24,311 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#69'.
2023-09-03 14:28:24,409 - Fetching 1 objects...
2023-09-03 14:28:24,410 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#70'.
2023-09-03 14:28:24,511 - Fetching 1 objects...
2023-09-03 14:28:24,512 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#71'.
2023-09-03 14:28:24,613 - Fetching 1 objects...
2023-09-03 14:28:24,614 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#72'.
2023-09-03 14:28:24,669 - Fetching 1 objects...
2023-09-03 14:28:24,670 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#73'.
2023-09-03 14:28:24,766 - Fetching 1 objects...
2023-09-03 14:28:24,767 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#74'.
2023-09-03 14:28:24,868 - Fetching 1 objects...
2023-09-03 14:28:24,869 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#75'.
2023-09-03 14:28:24,971 - Fetching 1 objects...
2023-09-03 14:28:24,971 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#76'.
2023-09-03 14:28:25,073 - Fetching 1 objects...
2023-09-03 14:28:25,075 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#77'.
2023-09-03 14:28:25,176 - Fetching 1 objects...
2023-09-03 14:28:25,177 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#78'.
2023-09-03 14:28:25,278 - Fetching 1 objects...
2023-09-03 14:28:25,279 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#79'.
2023-09-03 14:28:25,380 - Fetching 1 objects...
2023-09-03 14:28:25,381 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#80'.
2023-09-03 14:28:25,436 - Fetching 1 objects...
2023-09-03 14:28:25,436 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#81'.
2023-09-03 14:28:25,536 - Fetching 1 objects...
2023-09-03 14:28:25,537 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#82'.
2023-09-03 14:28:25,639 - Fetching 1 objects...
2023-09-03 14:28:25,639 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#83'.
2023-09-03 14:28:25,752 - Fetching 1 objects...
2023-09-03 14:28:25,753 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#84'.
2023-09-03 14:28:25,844 - Fetching 1 objects...
2023-09-03 14:28:25,845 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#85'.
2023-09-03 14:28:25,946 - Fetching 1 objects...
2023-09-03 14:28:25,946 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#86'.
2023-09-03 14:28:26,001 - Fetching 1 objects...
2023-09-03 14:28:26,001 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#87'.
2023-09-03 14:28:26,098 - Fetching 1 objects...
2023-09-03 14:28:26,098 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#88'.
2023-09-03 14:28:26,200 - Fetching 1 objects...
2023-09-03 14:28:26,201 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#90'.
2023-09-03 14:28:26,303 - Fetching 1 objects...
2023-09-03 14:28:26,304 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#91'.
2023-09-03 14:28:26,418 - Fetching 1 objects...
2023-09-03 14:28:26,419 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#92'.
2023-09-03 14:28:26,509 - Fetching 1 objects...
2023-09-03 14:28:26,511 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#93'.
2023-09-03 14:28:26,611 - Fetching 1 objects...
2023-09-03 14:28:26,612 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#94'.
2023-09-03 14:28:26,712 - Fetching 1 objects...
2023-09-03 14:28:26,713 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#95'.
2023-09-03 14:28:26,815 - Fetching 1 objects...
2023-09-03 14:28:26,818 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#96'.
2023-09-03 14:28:26,917 - Fetching 1 objects...
2023-09-03 14:28:26,918 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#97'.
2023-09-03 14:28:26,972 - Fetching 1 objects...
2023-09-03 14:28:26,973 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#98'.
2023-09-03 14:28:27,072 - Fetching 1 objects...
2023-09-03 14:28:27,073 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#99'.
2023-09-03 14:28:27,126 - Fetching 1 objects...
2023-09-03 14:28:27,127 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#100'.
2023-09-03 14:28:27,224 - Fetching 1 objects...
2023-09-03 14:28:27,225 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#101'.
2023-09-03 14:28:27,282 - Fetching 1 objects...
2023-09-03 14:28:27,282 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#102'.
2023-09-03 14:28:27,379 - Fetching 1 objects...
2023-09-03 14:28:27,380 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#104'.
2023-09-03 14:28:27,482 - Fetching 1 objects...
2023-09-03 14:28:27,483 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#103'.
2023-09-03 14:28:27,537 - Fetching 1 objects...
2023-09-03 14:28:27,553 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#105'.
2023-09-03 14:28:27,634 - Fetching 1 objects...
2023-09-03 14:28:27,635 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#106'.
2023-09-03 14:28:27,689 - Fetching 1 objects...
2023-09-03 14:28:27,690 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#107'.
2023-09-03 14:28:27,791 - Fetching 1 objects...
2023-09-03 14:28:27,792 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#108'.
2023-09-03 14:28:27,895 - Fetching 1 objects...
2023-09-03 14:28:27,896 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#109'.
2023-09-03 14:28:28,002 - Fetching 1 objects...
2023-09-03 14:28:28,003 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#110'.
2023-09-03 14:28:28,103 - Fetching 1 objects...
2023-09-03 14:28:28,104 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#111'.
2023-09-03 14:28:28,198 - Fetching 1 objects...
2023-09-03 14:28:28,199 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#112'.
2023-09-03 14:28:28,300 - Fetching 1 objects...
2023-09-03 14:28:28,301 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#113'.
2023-09-03 14:28:28,402 - Fetching 1 objects...
2023-09-03 14:28:28,404 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#114'.
2023-09-03 14:28:28,505 - Fetching 1 objects...
2023-09-03 14:28:28,506 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#115'.
2023-09-03 14:28:28,608 - Fetching 1 objects...
2023-09-03 14:28:28,608 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#117'.
2023-09-03 14:28:28,662 - Fetching 1 objects...
2023-09-03 14:28:28,662 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#119'.
2023-09-03 14:28:28,760 - Fetching 1 objects...
2023-09-03 14:28:28,761 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#120'.
2023-09-03 14:28:28,816 - Fetching 1 objects...
2023-09-03 14:28:28,817 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#121'.
2023-09-03 14:28:28,918 - Fetching 1 objects...
2023-09-03 14:28:28,919 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#122'.
2023-09-03 14:28:29,017 - Fetching 1 objects...
2023-09-03 14:28:29,018 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#124'.
2023-09-03 14:28:29,074 - Fetching 1 objects...
2023-09-03 14:28:29,075 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#125'.
2023-09-03 14:28:29,170 - Fetching 1 objects...
2023-09-03 14:28:29,171 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#126'.
2023-09-03 14:28:29,224 - Fetching 1 objects...
2023-09-03 14:28:29,225 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#127'.
2023-09-03 14:28:29,324 - Fetching 1 objects...
2023-09-03 14:28:29,325 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#118'.
2023-09-03 14:28:29,381 - Fetching 1 objects...
2023-09-03 14:28:29,382 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#116'.
2023-09-03 14:28:29,477 - Fetching 1 objects...
2023-09-03 14:28:29,478 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#129'.
2023-09-03 14:28:29,579 - Fetching 1 objects...
2023-09-03 14:28:29,580 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#130'.
2023-09-03 14:28:29,634 - Fetching 1 objects...
2023-09-03 14:28:29,635 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#131'.
2023-09-03 14:28:29,734 - Fetching 1 objects...
2023-09-03 14:28:29,735 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#132'.
2023-09-03 14:28:29,836 - Fetching 1 objects...
2023-09-03 14:28:29,836 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#133'.
2023-09-03 14:28:29,938 - Fetching 1 objects...
2023-09-03 14:28:29,939 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#134'.
2023-09-03 14:28:30,041 - Fetching 1 objects...
2023-09-03 14:28:30,042 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#135'.
2023-09-03 14:28:30,098 - Fetching 1 objects...
2023-09-03 14:28:30,098 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#136'.
2023-09-03 14:28:30,193 - Fetching 1 objects...
2023-09-03 14:28:30,195 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#138'.
2023-09-03 14:28:30,296 - Fetching 1 objects...
2023-09-03 14:28:30,297 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#137'.
2023-09-03 14:28:30,398 - Fetching 1 objects...
2023-09-03 14:28:30,399 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#139'.
2023-09-03 14:28:30,501 - Fetching 1 objects...
2023-09-03 14:28:30,501 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#140'.
2023-09-03 14:28:30,557 - Fetching 1 objects...
2023-09-03 14:28:30,558 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#141'.
2023-09-03 14:28:30,657 - Fetching 1 objects...
2023-09-03 14:28:30,657 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#142'.
2023-09-03 14:28:30,808 - Fetching 1 objects...
2023-09-03 14:28:30,809 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#143'.
2023-09-03 14:28:30,910 - Fetching 1 objects...
2023-09-03 14:28:30,911 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#144'.
2023-09-03 14:28:31,013 - Fetching 1 objects...
2023-09-03 14:28:31,013 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#145'.
2023-09-03 14:28:31,115 - Fetching 1 objects...
2023-09-03 14:28:31,116 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#146'.
2023-09-03 14:28:31,171 - Fetching 1 objects...
2023-09-03 14:28:31,172 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#147'.
2023-09-03 14:28:31,271 - Fetching 1 objects...
2023-09-03 14:28:31,272 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#149'.
2023-09-03 14:28:31,376 - Fetching 1 objects...
2023-09-03 14:28:31,377 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#150'.
2023-09-03 14:28:31,525 - Fetching 1 objects...
2023-09-03 14:28:31,525 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#151'.
2023-09-03 14:28:31,627 - Fetching 1 objects...
2023-09-03 14:28:31,628 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#152'.
2023-09-03 14:28:31,731 - Fetching 1 objects...
2023-09-03 14:28:31,731 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#148'.
2023-09-03 14:28:31,832 - Fetching 1 objects...
2023-09-03 14:28:31,833 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#153'.
2023-09-03 14:28:31,934 - Fetching 1 objects...
2023-09-03 14:28:31,935 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#154'.
2023-09-03 14:28:32,037 - Fetching 1 objects...
2023-09-03 14:28:32,038 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#155'.
2023-09-03 14:28:32,092 - Fetching 1 objects...
2023-09-03 14:28:32,093 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#156'.
2023-09-03 14:28:32,193 - Fetching 1 objects...
2023-09-03 14:28:32,193 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#157'.
2023-09-03 14:28:32,294 - Fetching 1 objects...
2023-09-03 14:28:32,295 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#158'.
2023-09-03 14:28:32,353 - Fetching 1 objects...
2023-09-03 14:28:32,354 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#159'.
2023-09-03 14:28:32,448 - Fetching 1 objects...
2023-09-03 14:28:32,449 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#160'.
2023-09-03 14:28:32,549 - Fetching 1 objects...
2023-09-03 14:28:32,550 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#161'.
2023-09-03 14:28:32,652 - Fetching 1 objects...
2023-09-03 14:28:32,652 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#162'.
2023-09-03 14:28:32,706 - Fetching 1 objects...
2023-09-03 14:28:32,707 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#163'.
2023-09-03 14:28:32,807 - Fetching 1 objects...
2023-09-03 14:28:32,808 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#164'.
2023-09-03 14:28:32,909 - Fetching 1 objects...
2023-09-03 14:28:32,909 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#165'.
2023-09-03 14:28:32,966 - Fetching 1 objects...
2023-09-03 14:28:32,967 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#166'.
2023-09-03 14:28:33,062 - Fetching 1 objects...
2023-09-03 14:28:33,063 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#167'.
2023-09-03 14:28:33,175 - Fetching 1 objects...
2023-09-03 14:28:33,176 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#168'.
2023-09-03 14:28:33,266 - Fetching 1 objects...
2023-09-03 14:28:33,267 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#169'.
2023-09-03 14:28:33,368 - Fetching 1 objects...
2023-09-03 14:28:33,369 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#170'.
2023-09-03 14:28:33,471 - Fetching 1 objects...
2023-09-03 14:28:33,472 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#171'.
2023-09-03 14:28:33,574 - Fetching 1 objects...
2023-09-03 14:28:33,576 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#172'.
2023-09-03 14:28:33,676 - Fetching 1 objects...
2023-09-03 14:28:33,676 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#173'.
2023-09-03 14:28:33,778 - Fetching 1 objects...
2023-09-03 14:28:33,779 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#174'.
2023-09-03 14:28:33,883 - Fetching 1 objects...
2023-09-03 14:28:33,884 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#175'.
2023-09-03 14:28:33,983 - Fetching 1 objects...
2023-09-03 14:28:33,983 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#176'.
2023-09-03 14:28:34,038 - Fetching 1 objects...
2023-09-03 14:28:34,039 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#177'.
2023-09-03 14:28:34,138 - Fetching 1 objects...
2023-09-03 14:28:34,139 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#178'.
2023-09-03 14:28:34,240 - Fetching 1 objects...
2023-09-03 14:28:34,241 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#179'.
2023-09-03 14:28:34,342 - Fetching 1 objects...
2023-09-03 14:28:34,343 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#180'.
2023-09-03 14:28:34,396 - Fetching 1 objects...
2023-09-03 14:28:34,397 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#181'.
2023-09-03 14:28:34,495 - Fetching 1 objects...
2023-09-03 14:28:34,496 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#182'.
2023-09-03 14:28:34,597 - Fetching 1 objects...
2023-09-03 14:28:34,598 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#183'.
2023-09-03 14:28:34,653 - Fetching 1 objects...
2023-09-03 14:28:34,654 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#184'.
2023-09-03 14:28:34,753 - Fetching 1 objects...
2023-09-03 14:28:34,756 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#189'.
2023-09-03 14:28:34,855 - Fetching 1 objects...
2023-09-03 14:28:34,856 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#192'.
2023-09-03 14:28:34,959 - Fetching 1 objects...
2023-09-03 14:28:34,960 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#193'.
2023-09-03 14:28:35,060 - Fetching 1 objects...
2023-09-03 14:28:35,061 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#194'.
2023-09-03 14:28:35,162 - Fetching 1 objects...
2023-09-03 14:28:35,163 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#196'.
2023-09-03 14:28:35,264 - Fetching 1 objects...
2023-09-03 14:28:35,265 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#198'.
2023-09-03 14:28:35,321 - Fetching 1 objects...
2023-09-03 14:28:35,321 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#197'.
2023-09-03 14:28:35,417 - Fetching 1 objects...
2023-09-03 14:28:35,418 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#199'.
2023-09-03 14:28:35,519 - Fetching 1 objects...
2023-09-03 14:28:35,520 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#200'.
2023-09-03 14:28:35,622 - Fetching 1 objects...
2023-09-03 14:28:35,624 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#201'.
2023-09-03 14:28:35,724 - Fetching 1 objects...
2023-09-03 14:28:35,724 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#202'.
2023-09-03 14:28:35,780 - Fetching 1 objects...
2023-09-03 14:28:35,781 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#203'.
2023-09-03 14:28:35,878 - Fetching 1 objects...
2023-09-03 14:28:35,879 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#204'.
2023-09-03 14:28:35,935 - Fetching 1 objects...
2023-09-03 14:28:35,936 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#207'.
2023-09-03 14:28:36,031 - Fetching 1 objects...
2023-09-03 14:28:36,031 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#208'.
2023-09-03 14:28:36,087 - Fetching 1 objects...
2023-09-03 14:28:36,088 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#209'.
2023-09-03 14:28:36,186 - Fetching 1 objects...
2023-09-03 14:28:36,187 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#210'.
2023-09-03 14:28:36,289 - Fetching 1 objects...
2023-09-03 14:28:36,290 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#211'.
2023-09-03 14:28:36,391 - Fetching 1 objects...
2023-09-03 14:28:36,391 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#212'.
2023-09-03 14:28:36,446 - Fetching 1 objects...
2023-09-03 14:28:36,447 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#213'.
2023-09-03 14:28:36,543 - Fetching 1 objects...
2023-09-03 14:28:36,544 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#214'.
2023-09-03 14:28:36,598 - Fetching 1 objects...
2023-09-03 14:28:36,599 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#215'.
2023-09-03 14:28:36,749 - Fetching 1 objects...
2023-09-03 14:28:36,750 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#216'.
2023-09-03 14:28:36,850 - Fetching 1 objects...
2023-09-03 14:28:36,851 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#217'.
2023-09-03 14:28:36,954 - Fetching 1 objects...
2023-09-03 14:28:36,955 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#219'.
2023-09-03 14:28:37,055 - Fetching 1 objects...
2023-09-03 14:28:37,056 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#218'.
2023-09-03 14:28:37,157 - Fetching 1 objects...
2023-09-03 14:28:37,161 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#220'.
2023-09-03 14:28:37,260 - Fetching 1 objects...
2023-09-03 14:28:37,261 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#221'.
2023-09-03 14:28:37,362 - Fetching 1 objects...
2023-09-03 14:28:37,363 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#222'.
2023-09-03 14:28:37,416 - Fetching 1 objects...
2023-09-03 14:28:37,417 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#223'.
2023-09-03 14:28:37,517 - Fetching 1 objects...
2023-09-03 14:28:37,518 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#224'.
2023-09-03 14:28:37,619 - Fetching 1 objects...
2023-09-03 14:28:37,620 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#225'.
2023-09-03 14:28:37,727 - Fetching 1 objects...
2023-09-03 14:28:37,728 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#226'.
2023-09-03 14:28:37,824 - Fetching 1 objects...
2023-09-03 14:28:37,825 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#227'.
2023-09-03 14:28:37,880 - Fetching 1 objects...
2023-09-03 14:28:37,881 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#228'.
2023-09-03 14:28:37,976 - Fetching 1 objects...
2023-09-03 14:28:37,977 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#229'.
2023-09-03 14:28:38,032 - Fetching 1 objects...
2023-09-03 14:28:38,033 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#230'.
2023-09-03 14:28:38,132 - Fetching 1 objects...
2023-09-03 14:28:38,134 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#231'.
2023-09-03 14:28:38,234 - Fetching 1 objects...
2023-09-03 14:28:38,235 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#232'.
2023-09-03 14:28:38,336 - Fetching 1 objects...
2023-09-03 14:28:38,337 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#233'.
2023-09-03 14:28:38,396 - Fetching 1 objects...
2023-09-03 14:28:38,397 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#234'.
2023-09-03 14:28:38,490 - Fetching 1 objects...
2023-09-03 14:28:38,491 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#235'.
2023-09-03 14:28:38,591 - Fetching 1 objects...
2023-09-03 14:28:38,592 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#236'.
2023-09-03 14:28:38,698 - Fetching 1 objects...
2023-09-03 14:28:38,698 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#237'.
2023-09-03 14:28:38,797 - Fetching 1 objects...
2023-09-03 14:28:38,798 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#238'.
2023-09-03 14:28:38,899 - Fetching 1 objects...
2023-09-03 14:28:38,900 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#239'.
2023-09-03 14:28:39,002 - Fetching 1 objects...
2023-09-03 14:28:39,003 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#240'.
2023-09-03 14:28:39,103 - Fetching 1 objects...
2023-09-03 14:28:39,103 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#241'.
2023-09-03 14:28:39,205 - Fetching 1 objects...
2023-09-03 14:28:39,206 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#242'.
2023-09-03 14:28:39,308 - Fetching 1 objects...
2023-09-03 14:28:39,309 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#244'.
2023-09-03 14:28:39,413 - Fetching 1 objects...
2023-09-03 14:28:39,414 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#245'.
2023-09-03 14:28:39,512 - Fetching 1 objects...
2023-09-03 14:28:39,513 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#246'.
2023-09-03 14:28:39,615 - Fetching 1 objects...
2023-09-03 14:28:39,615 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#247'.
2023-09-03 14:28:39,717 - Fetching 1 objects...
2023-09-03 14:28:39,718 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#248'.
2023-09-03 14:28:39,819 - Fetching 1 objects...
2023-09-03 14:28:39,830 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#249'.
2023-09-03 14:28:39,922 - Fetching 1 objects...
2023-09-03 14:28:39,922 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#250'.
2023-09-03 14:28:39,976 - Fetching 1 objects...
2023-09-03 14:28:39,977 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#251'.
2023-09-03 14:28:40,078 - Fetching 1 objects...
2023-09-03 14:28:40,079 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#252'.
2023-09-03 14:28:40,229 - Fetching 1 objects...
2023-09-03 14:28:40,230 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#253'.
2023-09-03 14:28:40,284 - Fetching 1 objects...
2023-09-03 14:28:40,285 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#254'.
2023-09-03 14:28:40,384 - Fetching 1 objects...
2023-09-03 14:28:40,385 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#255'.
2023-09-03 14:28:40,441 - Fetching 1 objects...
2023-09-03 14:28:40,441 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#256'.
2023-09-03 14:28:40,536 - Fetching 1 objects...
2023-09-03 14:28:40,537 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#257'.
2023-09-03 14:28:40,593 - Fetching 1 objects...
2023-09-03 14:28:40,595 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#258'.
2023-09-03 14:28:40,692 - Fetching 1 objects...
2023-09-03 14:28:40,693 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#259'.
2023-09-03 14:28:40,796 - Fetching 1 objects...
2023-09-03 14:28:40,797 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#265'.
2023-09-03 14:28:40,896 - Fetching 1 objects...
2023-09-03 14:28:40,897 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#266'.
2023-09-03 14:28:40,953 - Fetching 1 objects...
2023-09-03 14:28:40,954 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#275'.
2023-09-03 14:28:41,048 - Fetching 1 objects...
2023-09-03 14:28:41,049 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#276'.
2023-09-03 14:28:41,105 - Fetching 1 objects...
2023-09-03 14:28:41,105 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#277'.
2023-09-03 14:28:41,204 - Fetching 1 objects...
2023-09-03 14:28:41,205 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#278'.
2023-09-03 14:28:41,308 - Fetching 1 objects...
2023-09-03 14:28:41,309 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#382'.
2023-09-03 14:28:41,409 - Fetching 1 objects...
2023-09-03 14:28:41,410 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#383'.
2023-09-03 14:28:41,511 - Fetching 1 objects...
2023-09-03 14:28:41,512 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#384'.
2023-09-03 14:28:41,612 - Fetching 1 objects...
2023-09-03 14:28:41,613 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#463'.
2023-09-03 14:28:41,671 - Fetching 1 objects...
2023-09-03 14:28:41,671 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#386'.
2023-09-03 14:28:41,766 - Fetching 1 objects...
2023-09-03 14:28:41,767 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#387'.
2023-09-03 14:28:41,868 - Fetching 1 objects...
2023-09-03 14:28:41,868 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#388'.
2023-09-03 14:28:41,970 - Fetching 1 objects...
2023-09-03 14:28:41,971 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#389'.
2023-09-03 14:28:42,024 - Fetching 1 objects...
2023-09-03 14:28:42,025 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#390'.
2023-09-03 14:28:42,124 - Fetching 1 objects...
2023-09-03 14:28:42,125 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#391'.
2023-09-03 14:28:42,179 - Fetching 1 objects...
2023-09-03 14:28:42,179 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#394'.
2023-09-03 14:28:42,277 - Fetching 1 objects...
2023-09-03 14:28:42,279 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#395'.
2023-09-03 14:28:42,380 - Fetching 1 objects...
2023-09-03 14:28:42,381 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#397'.
2023-09-03 14:28:42,482 - Fetching 1 objects...
2023-09-03 14:28:42,483 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#398'.
2023-09-03 14:28:42,585 - Fetching 1 objects...
2023-09-03 14:28:42,586 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#399'.
2023-09-03 14:28:42,689 - Fetching 1 objects...
2023-09-03 14:28:42,690 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#400'.
2023-09-03 14:28:42,791 - Fetching 1 objects...
2023-09-03 14:28:42,791 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#401'.
2023-09-03 14:28:42,892 - Fetching 1 objects...
2023-09-03 14:28:42,893 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#402'.
2023-09-03 14:28:42,947 - Fetching 1 objects...
2023-09-03 14:28:42,948 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#403'.
2023-09-03 14:28:43,048 - Fetching 1 objects...
2023-09-03 14:28:43,048 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#404'.
2023-09-03 14:28:43,148 - Fetching 1 objects...
2023-09-03 14:28:43,149 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#405'.
2023-09-03 14:28:43,207 - Fetching 1 objects...
2023-09-03 14:28:43,208 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#406'.
2023-09-03 14:28:43,302 - Fetching 1 objects...
2023-09-03 14:28:43,304 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#407'.
2023-09-03 14:28:43,405 - Fetching 1 objects...
2023-09-03 14:28:43,406 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#408'.
2023-09-03 14:28:43,506 - Fetching 1 objects...
2023-09-03 14:28:43,507 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#410'.
2023-09-03 14:28:43,613 - Fetching 1 objects...
2023-09-03 14:28:43,614 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#411'.
2023-09-03 14:28:43,712 - Fetching 1 objects...
2023-09-03 14:28:43,712 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#412'.
2023-09-03 14:28:43,767 - Fetching 1 objects...
2023-09-03 14:28:43,768 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#414'.
2023-09-03 14:28:43,916 - Fetching 1 objects...
2023-09-03 14:28:43,917 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#419'.
2023-09-03 14:28:44,018 - Fetching 1 objects...
2023-09-03 14:28:44,019 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#420'.
2023-09-03 14:28:44,121 - Fetching 1 objects...
2023-09-03 14:28:44,121 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#421'.
2023-09-03 14:28:44,180 - Fetching 1 objects...
2023-09-03 14:28:44,181 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#422'.
2023-09-03 14:28:44,277 - Fetching 1 objects...
2023-09-03 14:28:44,280 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#424'.
2023-09-03 14:28:44,379 - Fetching 1 objects...
2023-09-03 14:28:44,380 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#425'.
2023-09-03 14:28:44,480 - Fetching 1 objects...
2023-09-03 14:28:44,480 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#427'.
2023-09-03 14:28:44,536 - Fetching 1 objects...
2023-09-03 14:28:44,536 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#426'.
2023-09-03 14:28:44,632 - Fetching 1 objects...
2023-09-03 14:28:44,633 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#428'.
2023-09-03 14:28:44,734 - Fetching 1 objects...
2023-09-03 14:28:44,736 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#429'.
2023-09-03 14:28:44,796 - Fetching 1 objects...
2023-09-03 14:28:44,797 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#430'.
2023-09-03 14:28:44,939 - Fetching 1 objects...
2023-09-03 14:28:44,941 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#431'.
2023-09-03 14:28:45,042 - Fetching 1 objects...
2023-09-03 14:28:45,043 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#453'.
2023-09-03 14:28:45,145 - Fetching 1 objects...
2023-09-03 14:28:45,145 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#469'.
2023-09-03 14:28:45,247 - Fetching 1 objects...
2023-09-03 14:28:45,247 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#470'.
2023-09-03 14:28:45,302 - Fetching 1 objects...
2023-09-03 14:28:45,303 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#475'.
imho, that's so strange and after that it seems to hit DB to load LookupGroup#1
2023-09-03 14:28:45,458 - loading entity: [Entities.LookupGroup#1]
2023-09-03 14:28:45,466 - Opened new DbCommand, open DbCommands: 2
2023-09-03 14:28:45,467 - Building an DbCommand object for the SqlString: /* load Entities.LookupGroup */ SELECT lookupgrou0_.ID as id1_62_0_, lookupgrou0_.Name as name2_62_0_ FROM dbo.LookupGroup lookupgrou0_ WHERE lookupgrou0_.ID=?
2023-09-03 14:28:45,468 - binding '1' to parameter: 0
2023-09-03 14:28:45,469 - /* load Entities.LookupGroup */ SELECT lookupgrou0_.ID as id1_62_0_, lookupgrou0_.Name as name2_62_0_ FROM dbo.LookupGroup lookupgrou0_ WHERE lookupgrou0_.ID=@p0;@p0 = 1 [Type: Int64 (0:0:0)]
2023-09-03 14:28:45,470 - Enlist Command
2023-09-03 14:28:45,495 - ExecuteReader took 24 ms
2023-09-03 14:28:45,495 - Opened DbDataReader, open DbDataReaders: 1
2023-09-03 14:28:45,496 - processing result set
2023-09-03 14:28:45,498 - result set row: 0
2023-09-03 14:28:45,499 - result row: EntityKey[Entities.LookupGroup#1]
2023-09-03 14:28:45,503 - Initializing object from DataReader: [Entities.LookupGroup#1]
2023-09-03 14:28:45,504 - Hydrating entity: [Entities.LookupGroup#1]
And then it tries to cache that record into Redis:
2023-09-03 14:28:45,561 - resolving associations for [Entities.LookupGroup#1]
2023-09-03 14:28:45,564 - adding entity to second-level cache: [Entities.LookupGroup#1]
2023-09-03 14:28:45,565 - Adding a put operation to batch for entity Entities.LookupGroup and key Entities.LookupGroup#1
2023-09-03 14:28:45,566 - done materializing entity [Entities.LookupGroup#1]
2023-09-03 14:28:45,567 - Caching: Entities.LookupGroup#1
2023-09-03 14:28:45,567 - Locking 1 objects...
2023-09-03 14:28:45,568 - Locking object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#1'.
2023-09-03 14:28:45,659 - Fetching 1 objects...
2023-09-03 14:28:45,660 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#1'.
2023-09-03 14:28:45,765 - Cached: Entities.LookupGroup#1
2023-09-03 14:28:45,766 - Putting 1 objects...
2023-09-03 14:28:45,766 - Putting object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#1'.
2023-09-03 14:28:45,862 - Unlocking 1 objects...
2023-09-03 14:28:45,863 - Unlocking object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#1'.
2023-09-03 14:28:45,966 - Number of unlocked objects with keys ('{NHibernate-Cache:lookups}-1:Entities.LookupGroup#1'): 1
2023-09-03 14:28:45,967 - ExecuteBatch for 1 batches totaling 1 keys took 399 ms
After that it will repeat the same pattern with new LookupGroup id = 2
2023-09-03 14:28:46,708 - loading entity: [Entities.LookupGroup#2]
2023-09-03 14:28:46,708 - attempting to resolve: [Entities.LookupGroup#2]
2023-09-03 14:28:46,709 - Cache lookup: Entities.LookupGroup#2,Entities.LookupGroup#3,Entities.LookupGroup#4,Entities.LookupGroup#5,Entities.LookupGroup#6,Entities.LookupGroup#8,Entities.LookupGroup#9,Entities.LookupGroup#10,Entities.LookupGroup#7,Entities.LookupGroup#11,Entities.LookupGroup#12,Entities.LookupGroup#13,Entities.LookupGroup#14,Entities.LookupGroup#15,Entities.LookupGroup#16,Entities.LookupGroup#17,Entities.LookupGroup#18,Entities.LookupGroup#462,Entities.LookupGroup#19,Entities.LookupGroup#20,Entities.LookupGroup#21,Entities.LookupGroup#22,Entities.LookupGroup#23,Entities.LookupGroup#24,Entities.LookupGroup#27
2023-09-03 14:28:46,711 - Fetching 25 objects...
2023-09-03 14:28:46,712 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#2'.
2023-09-03 14:28:46,713 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#3'.
2023-09-03 14:28:46,717 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#4'.
2023-09-03 14:28:46,718 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#5'.
2023-09-03 14:28:46,720 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#6'.
2023-09-03 14:28:46,720 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#8'.
2023-09-03 14:28:46,721 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#9'.
2023-09-03 14:28:46,722 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#10'.
2023-09-03 14:28:46,723 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#7'.
2023-09-03 14:28:46,727 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#11'.
2023-09-03 14:28:46,729 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#12'.
2023-09-03 14:28:46,730 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#13'.
2023-09-03 14:28:46,730 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#14'.
2023-09-03 14:28:46,731 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#15'.
2023-09-03 14:28:46,732 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#16'.
2023-09-03 14:28:46,733 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#17'.
2023-09-03 14:28:46,733 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#18'.
2023-09-03 14:28:46,734 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#462'.
2023-09-03 14:28:46,734 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#19'.
2023-09-03 14:28:46,735 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#20'.
2023-09-03 14:28:46,736 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#21'.
2023-09-03 14:28:46,736 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#22'.
2023-09-03 14:28:46,737 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#23'.
2023-09-03 14:28:46,737 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#24'.
2023-09-03 14:28:46,738 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#27'.
2023-09-03 14:28:46,887 - Cached item was locked: Entities.LookupGroup#2
2023-09-03 14:28:46,887 - Cached item was locked: Entities.LookupGroup#3
2023-09-03 14:28:46,888 - Cached item was locked: Entities.LookupGroup#4
2023-09-03 14:28:46,888 - Cached item was locked: Entities.LookupGroup#5
2023-09-03 14:28:46,889 - Cached item was locked: Entities.LookupGroup#6
2023-09-03 14:28:46,890 - Cached item was locked: Entities.LookupGroup#8
2023-09-03 14:28:46,890 - Cached item was locked: Entities.LookupGroup#9
2023-09-03 14:28:46,890 - Cached item was locked: Entities.LookupGroup#10
2023-09-03 14:28:46,891 - Cached item was locked: Entities.LookupGroup#7
2023-09-03 14:28:46,892 - Cached item was locked: Entities.LookupGroup#11
2023-09-03 14:28:46,893 - Cached item was locked: Entities.LookupGroup#12
2023-09-03 14:28:46,894 - Cached item was locked: Entities.LookupGroup#13
2023-09-03 14:28:46,895 - Cached item was locked: Entities.LookupGroup#14
2023-09-03 14:28:46,895 - Cached item was locked: Entities.LookupGroup#15
2023-09-03 14:28:46,896 - Cached item was locked: Entities.LookupGroup#16
2023-09-03 14:28:46,897 - Cached item was locked: Entities.LookupGroup#17
2023-09-03 14:28:46,898 - Cached item was locked: Entities.LookupGroup#18
2023-09-03 14:28:46,898 - Cached item was locked: Entities.LookupGroup#462
2023-09-03 14:28:46,899 - Cached item was locked: Entities.LookupGroup#19
2023-09-03 14:28:46,900 - Cached item was locked: Entities.LookupGroup#20
2023-09-03 14:28:46,901 - Cached item was locked: Entities.LookupGroup#21
2023-09-03 14:28:46,901 - Cached item was locked: Entities.LookupGroup#22
2023-09-03 14:28:46,902 - Cached item was locked: Entities.LookupGroup#23
2023-09-03 14:28:46,902 - Cached item was locked: Entities.LookupGroup#24
2023-09-03 14:28:46,903 - Cached item was locked: Entities.LookupGroup#27
2023-09-03 14:28:46,903 - Entity cache miss: Entities.LookupGroup#2
2023-09-03 14:28:46,905 - object not resolved in any cache: [Entities.LookupGroup#2]
2023-09-03 14:28:46,905 - Fetching entity: [Entities.LookupGroup#2]
2023-09-03 14:28:46,906 - Fetching 25 objects...
2023-09-03 14:28:46,907 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#3'.
2023-09-03 14:28:46,907 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#4'.
2023-09-03 14:28:46,907 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#5'.
2023-09-03 14:28:46,908 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#6'.
2023-09-03 14:28:46,908 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#8'.
2023-09-03 14:28:46,909 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#9'.
2023-09-03 14:28:46,910 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#10'.
2023-09-03 14:28:46,910 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#7'.
2023-09-03 14:28:46,911 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#11'.
2023-09-03 14:28:46,911 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#12'.
2023-09-03 14:28:46,912 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#13'.
2023-09-03 14:28:46,913 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#14'.
2023-09-03 14:28:46,913 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#15'.
2023-09-03 14:28:46,915 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#16'.
2023-09-03 14:28:46,917 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#17'.
2023-09-03 14:28:46,918 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#18'.
2023-09-03 14:28:46,919 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#462'.
2023-09-03 14:28:46,919 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#19'.
2023-09-03 14:28:46,920 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#20'.
2023-09-03 14:28:46,920 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#21'.
2023-09-03 14:28:46,921 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#22'.
2023-09-03 14:28:46,922 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#23'.
2023-09-03 14:28:46,922 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#24'.
2023-09-03 14:28:46,923 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#27'.
2023-09-03 14:28:46,924 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#28'.
2023-09-03 14:28:46,990 - Fetching 1 objects...
2023-09-03 14:28:46,990 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#29'.
2023-09-03 14:28:47,090 - Fetching 1 objects...
2023-09-03 14:28:47,091 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#30'.
2023-09-03 14:28:47,193 - Fetching 1 objects...
2023-09-03 14:28:47,194 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#31'.
2023-09-03 14:28:47,295 - Fetching 1 objects...
2023-09-03 14:28:47,296 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#32'.
2023-09-03 14:28:47,397 - Fetching 1 objects...
2023-09-03 14:28:47,398 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#33'.
2023-09-03 14:28:47,501 - Fetching 1 objects...
2023-09-03 14:28:47,502 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#34'.
2023-09-03 14:28:47,602 - Fetching 1 objects...
2023-09-03 14:28:47,603 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#35'.
2023-09-03 14:28:47,704 - Fetching 1 objects...
2023-09-03 14:28:47,705 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#36'.
2023-09-03 14:28:47,758 - Fetching 1 objects...
2023-09-03 14:28:47,759 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#37'.
2023-09-03 14:28:47,861 - Fetching 1 objects...
2023-09-03 14:28:47,865 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#38'.
2023-09-03 14:28:47,962 - Fetching 1 objects...
2023-09-03 14:28:47,962 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#39'.
2023-09-03 14:28:48,018 - Fetching 1 objects...
2023-09-03 14:28:48,018 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#40'.
2023-09-03 14:28:48,114 - Fetching 1 objects...
2023-09-03 14:28:48,115 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#41'.
2023-09-03 14:28:48,218 - Fetching 1 objects...
2023-09-03 14:28:48,219 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#42'.
2023-09-03 14:28:48,319 - Fetching 1 objects...
2023-09-03 14:28:48,320 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#43'.
2023-09-03 14:28:48,421 - Fetching 1 objects...
2023-09-03 14:28:48,422 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#44'.
2023-09-03 14:28:48,476 - Fetching 1 objects...
2023-09-03 14:28:48,477 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#45'.
2023-09-03 14:28:48,579 - Fetching 1 objects...
2023-09-03 14:28:48,580 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#46'.
2023-09-03 14:28:48,678 - Fetching 1 objects...
2023-09-03 14:28:48,679 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#47'.
2023-09-03 14:28:48,734 - Fetching 1 objects...
2023-09-03 14:28:48,735 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#48'.
2023-09-03 14:28:48,835 - Fetching 1 objects...
2023-09-03 14:28:48,836 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#49'.
2023-09-03 14:28:48,934 - Fetching 1 objects...
2023-09-03 14:28:48,935 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#50'.
2023-09-03 14:28:49,036 - Fetching 1 objects...
2023-09-03 14:28:49,036 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#51'.
2023-09-03 14:28:49,091 - Fetching 1 objects...
2023-09-03 14:28:49,092 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#52'.
2023-09-03 14:28:49,193 - Fetching 1 objects...
2023-09-03 14:28:49,194 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#53'.
2023-09-03 14:28:49,293 - Fetching 1 objects...
2023-09-03 14:28:49,293 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#54'.
2023-09-03 14:28:49,351 - Fetching 1 objects...
2023-09-03 14:28:49,351 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#55'.
2023-09-03 14:28:49,446 - Fetching 1 objects...
2023-09-03 14:28:49,446 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#56'.
2023-09-03 14:28:49,548 - Fetching 1 objects...
2023-09-03 14:28:49,548 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#57'.
2023-09-03 14:28:49,650 - Fetching 1 objects...
2023-09-03 14:28:49,651 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#58'.
2023-09-03 14:28:49,706 - Fetching 1 objects...
2023-09-03 14:28:49,707 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#59'.
2023-09-03 14:28:49,806 - Fetching 1 objects...
2023-09-03 14:28:49,807 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#60'.
2023-09-03 14:28:49,916 - Fetching 1 objects...
2023-09-03 14:28:49,916 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#61'.
2023-09-03 14:28:50,010 - Fetching 1 objects...
2023-09-03 14:28:50,011 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#62'.
2023-09-03 14:28:50,112 - Fetching 1 objects...
2023-09-03 14:28:50,113 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#63'.
2023-09-03 14:28:50,168 - Fetching 1 objects...
2023-09-03 14:28:50,169 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#64'.
2023-09-03 14:28:50,264 - Fetching 1 objects...
2023-09-03 14:28:50,265 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#65'.
2023-09-03 14:28:50,369 - Fetching 1 objects...
2023-09-03 14:28:50,370 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#66'.
2023-09-03 14:28:50,470 - Fetching 1 objects...
2023-09-03 14:28:50,470 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#67'.
2023-09-03 14:28:50,572 - Fetching 1 objects...
2023-09-03 14:28:50,573 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#68'.
2023-09-03 14:28:50,627 - Fetching 1 objects...
2023-09-03 14:28:50,628 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#69'.
2023-09-03 14:28:50,726 - Fetching 1 objects...
2023-09-03 14:28:50,729 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#70'.
2023-09-03 14:28:50,829 - Fetching 1 objects...
2023-09-03 14:28:50,830 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#71'.
2023-09-03 14:28:50,885 - Fetching 1 objects...
2023-09-03 14:28:50,885 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#72'.
2023-09-03 14:28:50,982 - Fetching 1 objects...
2023-09-03 14:28:50,983 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#73'.
2023-09-03 14:28:51,084 - Fetching 1 objects...
2023-09-03 14:28:51,085 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#74'.
2023-09-03 14:28:51,186 - Fetching 1 objects...
2023-09-03 14:28:51,187 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#75'.
2023-09-03 14:28:51,289 - Fetching 1 objects...
2023-09-03 14:28:51,290 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#76'.
2023-09-03 14:28:51,344 - Fetching 1 objects...
2023-09-03 14:28:51,345 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#77'.
2023-09-03 14:28:51,445 - Fetching 1 objects...
2023-09-03 14:28:51,446 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#78'.
2023-09-03 14:28:51,546 - Fetching 1 objects...
2023-09-03 14:28:51,547 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#79'.
2023-09-03 14:28:51,605 - Fetching 1 objects...
2023-09-03 14:28:51,605 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#80'.
2023-09-03 14:28:51,698 - Fetching 1 objects...
2023-09-03 14:28:51,699 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#81'.
2023-09-03 14:28:51,804 - Fetching 1 objects...
2023-09-03 14:28:51,805 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#82'.
2023-09-03 14:28:51,903 - Fetching 1 objects...
2023-09-03 14:28:51,905 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#83'.
2023-09-03 14:28:52,006 - Fetching 1 objects...
2023-09-03 14:28:52,006 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#84'.
2023-09-03 14:28:52,060 - Fetching 1 objects...
2023-09-03 14:28:52,083 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#85'.
2023-09-03 14:28:52,162 - Fetching 1 objects...
2023-09-03 14:28:52,163 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#86'.
2023-09-03 14:28:52,262 - Fetching 1 objects...
2023-09-03 14:28:52,263 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#87'.
2023-09-03 14:28:52,319 - Fetching 1 objects...
2023-09-03 14:28:52,320 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#88'.
2023-09-03 14:28:52,415 - Fetching 1 objects...
2023-09-03 14:28:52,416 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#90'.
2023-09-03 14:28:52,518 - Fetching 1 objects...
2023-09-03 14:28:52,519 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#91'.
2023-09-03 14:28:52,620 - Fetching 1 objects...
2023-09-03 14:28:52,621 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#92'.
2023-09-03 14:28:52,722 - Fetching 1 objects...
2023-09-03 14:28:52,723 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#93'.
2023-09-03 14:28:52,825 - Fetching 1 objects...
2023-09-03 14:28:52,826 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#94'.
2023-09-03 14:28:52,931 - Fetching 1 objects...
2023-09-03 14:28:52,932 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#95'.
2023-09-03 14:28:53,030 - Fetching 1 objects...
2023-09-03 14:28:53,030 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#96'.
2023-09-03 14:28:53,084 - Fetching 1 objects...
2023-09-03 14:28:53,085 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#97'.
2023-09-03 14:28:53,184 - Fetching 1 objects...
2023-09-03 14:28:53,185 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#98'.
2023-09-03 14:28:53,240 - Fetching 1 objects...
2023-09-03 14:28:53,241 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#99'.
2023-09-03 14:28:53,337 - Fetching 1 objects...
2023-09-03 14:28:53,337 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#100'.
2023-09-03 14:28:53,392 - Fetching 1 objects...
2023-09-03 14:28:53,393 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#101'.
2023-09-03 14:28:53,542 - Fetching 1 objects...
2023-09-03 14:28:53,542 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#102'.
2023-09-03 14:28:53,596 - Fetching 1 objects...
2023-09-03 14:28:53,597 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#104'.
2023-09-03 14:28:53,696 - Fetching 1 objects...
2023-09-03 14:28:53,697 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#103'.
2023-09-03 14:28:53,801 - Fetching 1 objects...
2023-09-03 14:28:53,802 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#105'.
2023-09-03 14:28:53,906 - Fetching 1 objects...
2023-09-03 14:28:53,906 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#106'.
2023-09-03 14:28:54,004 - Fetching 1 objects...
2023-09-03 14:28:54,004 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#107'.
2023-09-03 14:28:54,106 - Fetching 1 objects...
2023-09-03 14:28:54,107 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#108'.
2023-09-03 14:28:54,212 - Fetching 1 objects...
2023-09-03 14:28:54,213 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#109'.
2023-09-03 14:28:54,310 - Fetching 1 objects...
2023-09-03 14:28:54,310 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#110'.
2023-09-03 14:28:54,372 - Fetching 1 objects...
2023-09-03 14:28:54,373 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#111'.
2023-09-03 14:28:54,463 - Fetching 1 objects...
2023-09-03 14:28:54,465 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#112'.
2023-09-03 14:28:54,566 - Fetching 1 objects...
2023-09-03 14:28:54,567 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#113'.
2023-09-03 14:28:54,670 - Fetching 1 objects...
2023-09-03 14:28:54,673 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#114'.
2023-09-03 14:28:54,774 - Fetching 1 objects...
2023-09-03 14:28:54,775 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#115'.
2023-09-03 14:28:54,872 - Fetching 1 objects...
2023-09-03 14:28:54,873 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#117'.
2023-09-03 14:28:54,928 - Fetching 1 objects...
2023-09-03 14:28:54,929 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#119'.
2023-09-03 14:28:55,028 - Fetching 1 objects...
2023-09-03 14:28:55,028 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#120'.
2023-09-03 14:28:55,130 - Fetching 1 objects...
2023-09-03 14:28:55,130 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#121'.
2023-09-03 14:28:55,188 - Fetching 1 objects...
2023-09-03 14:28:55,188 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#122'.
2023-09-03 14:28:55,282 - Fetching 1 objects...
2023-09-03 14:28:55,283 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#124'.
2023-09-03 14:28:55,384 - Fetching 1 objects...
2023-09-03 14:28:55,385 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#125'.
2023-09-03 14:28:55,440 - Fetching 1 objects...
2023-09-03 14:28:55,441 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#126'.
2023-09-03 14:28:55,540 - Fetching 1 objects...
2023-09-03 14:28:55,541 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#127'.
2023-09-03 14:28:55,642 - Fetching 1 objects...
2023-09-03 14:28:55,642 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#118'.
2023-09-03 14:28:55,698 - Fetching 1 objects...
2023-09-03 14:28:55,699 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#116'.
2023-09-03 14:28:55,795 - Fetching 1 objects...
2023-09-03 14:28:55,796 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#129'.
2023-09-03 14:28:55,898 - Fetching 1 objects...
2023-09-03 14:28:55,898 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#130'.
2023-09-03 14:28:56,000 - Fetching 1 objects...
2023-09-03 14:28:56,001 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#131'.
2023-09-03 14:28:56,110 - Fetching 1 objects...
2023-09-03 14:28:56,111 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#132'.
2023-09-03 14:28:56,205 - Fetching 1 objects...
2023-09-03 14:28:56,206 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#133'.
2023-09-03 14:28:56,316 - Fetching 1 objects...
2023-09-03 14:28:56,317 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#134'.
2023-09-03 14:28:56,408 - Fetching 1 objects...
2023-09-03 14:28:56,409 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#135'.
2023-09-03 14:28:56,464 - Fetching 1 objects...
2023-09-03 14:28:56,465 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#136'.
2023-09-03 14:28:56,570 - Fetching 1 objects...
2023-09-03 14:28:56,572 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#138'.
2023-09-03 14:28:56,666 - Fetching 1 objects...
2023-09-03 14:28:56,667 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#137'.
2023-09-03 14:28:56,725 - Fetching 1 objects...
2023-09-03 14:28:56,725 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#139'.
2023-09-03 14:28:56,818 - Fetching 1 objects...
2023-09-03 14:28:56,819 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#140'.
2023-09-03 14:28:56,920 - Fetching 1 objects...
2023-09-03 14:28:56,921 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#141'.
2023-09-03 14:28:57,023 - Fetching 1 objects...
2023-09-03 14:28:57,023 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#142'.
2023-09-03 14:28:57,129 - Fetching 1 objects...
2023-09-03 14:28:57,129 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#143'.
2023-09-03 14:28:57,228 - Fetching 1 objects...
2023-09-03 14:28:57,228 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#144'.
2023-09-03 14:28:57,330 - Fetching 1 objects...
2023-09-03 14:28:57,331 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#145'.
2023-09-03 14:28:57,386 - Fetching 1 objects...
2023-09-03 14:28:57,387 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#146'.
2023-09-03 14:28:57,485 - Fetching 1 objects...
2023-09-03 14:28:57,486 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#147'.
2023-09-03 14:28:57,593 - Fetching 1 objects...
2023-09-03 14:28:57,604 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#149'.
2023-09-03 14:28:57,748 - Fetching 1 objects...
2023-09-03 14:28:57,749 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#150'.
2023-09-03 14:28:57,844 - Fetching 1 objects...
2023-09-03 14:28:57,851 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#151'.
2023-09-03 14:28:57,945 - Fetching 1 objects...
2023-09-03 14:28:57,945 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#152'.
2023-09-03 14:28:58,052 - Fetching 1 objects...
2023-09-03 14:28:58,052 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#148'.
2023-09-03 14:28:58,149 - Fetching 1 objects...
2023-09-03 14:28:58,150 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#153'.
2023-09-03 14:28:58,251 - Fetching 1 objects...
2023-09-03 14:28:58,252 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#154'.
2023-09-03 14:28:58,359 - Fetching 1 objects...
2023-09-03 14:28:58,361 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#155'.
2023-09-03 14:28:58,458 - Fetching 1 objects...
2023-09-03 14:28:58,459 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#156'.
2023-09-03 14:28:58,559 - Fetching 1 objects...
2023-09-03 14:28:58,560 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#157'.
2023-09-03 14:28:58,662 - Fetching 1 objects...
2023-09-03 14:28:58,662 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#158'.
2023-09-03 14:28:58,768 - Fetching 1 objects...
2023-09-03 14:28:58,769 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#159'.
2023-09-03 14:28:58,866 - Fetching 1 objects...
2023-09-03 14:28:58,867 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#160'.
2023-09-03 14:28:58,971 - Fetching 1 objects...
2023-09-03 14:28:58,972 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#161'.
2023-09-03 14:28:59,071 - Fetching 1 objects...
2023-09-03 14:28:59,073 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#162'.
2023-09-03 14:28:59,188 - Fetching 1 objects...
2023-09-03 14:28:59,191 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#163'.
2023-09-03 14:28:59,296 - Fetching 1 objects...
2023-09-03 14:28:59,296 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#164'.
2023-09-03 14:28:59,388 - Fetching 1 objects...
2023-09-03 14:28:59,388 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#165'.
2023-09-03 14:28:59,483 - Fetching 1 objects...
2023-09-03 14:28:59,484 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#166'.
2023-09-03 14:28:59,591 - Fetching 1 objects...
2023-09-03 14:28:59,592 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#167'.
2023-09-03 14:28:59,687 - Fetching 1 objects...
2023-09-03 14:28:59,688 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#168'.
2023-09-03 14:28:59,789 - Fetching 1 objects...
2023-09-03 14:28:59,790 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#169'.
2023-09-03 14:28:59,896 - Fetching 1 objects...
2023-09-03 14:28:59,897 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#170'.
2023-09-03 14:28:59,994 - Fetching 1 objects...
2023-09-03 14:28:59,995 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#171'.
2023-09-03 14:29:00,118 - Fetching 1 objects...
2023-09-03 14:29:00,118 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#172'.
2023-09-03 14:29:00,203 - Fetching 1 objects...
2023-09-03 14:29:00,204 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#173'.
2023-09-03 14:29:00,289 - Fetching 1 objects...
2023-09-03 14:29:00,290 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#174'.
2023-09-03 14:29:00,346 - Fetching 1 objects...
2023-09-03 14:29:00,349 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#175'.
2023-09-03 14:29:00,405 - Fetching 1 objects...
2023-09-03 14:29:00,405 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#176'.
2023-09-03 14:29:00,509 - Fetching 1 objects...
2023-09-03 14:29:00,509 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#177'.
2023-09-03 14:29:00,608 - Fetching 1 objects...
2023-09-03 14:29:00,610 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#178'.
2023-09-03 14:29:00,710 - Fetching 1 objects...
2023-09-03 14:29:00,712 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#179'.
2023-09-03 14:29:00,806 - Fetching 1 objects...
2023-09-03 14:29:00,807 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#180'.
2023-09-03 14:29:00,866 - Fetching 1 objects...
2023-09-03 14:29:00,867 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#181'.
2023-09-03 14:29:00,961 - Fetching 1 objects...
2023-09-03 14:29:00,966 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#182'.
2023-09-03 14:29:01,021 - Fetching 1 objects...
2023-09-03 14:29:01,022 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#183'.
2023-09-03 14:29:01,120 - Fetching 1 objects...
2023-09-03 14:29:01,121 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#184'.
2023-09-03 14:29:01,174 - Fetching 1 objects...
2023-09-03 14:29:01,176 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#189'.
2023-09-03 14:29:01,274 - Fetching 1 objects...
2023-09-03 14:29:01,275 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#192'.
2023-09-03 14:29:01,333 - Fetching 1 objects...
2023-09-03 14:29:01,334 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#193'.
2023-09-03 14:29:01,428 - Fetching 1 objects...
2023-09-03 14:29:01,429 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#194'.
2023-09-03 14:29:01,531 - Fetching 1 objects...
2023-09-03 14:29:01,532 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#196'.
2023-09-03 14:29:01,632 - Fetching 1 objects...
2023-09-03 14:29:01,633 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#198'.
2023-09-03 14:29:01,735 - Fetching 1 objects...
2023-09-03 14:29:01,736 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#197'.
2023-09-03 14:29:01,837 - Fetching 1 objects...
2023-09-03 14:29:01,838 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#199'.
2023-09-03 14:29:01,940 - Fetching 1 objects...
2023-09-03 14:29:01,941 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#200'.
2023-09-03 14:29:02,042 - Fetching 1 objects...
2023-09-03 14:29:02,042 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#201'.
2023-09-03 14:29:02,144 - Fetching 1 objects...
2023-09-03 14:29:02,145 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#202'.
2023-09-03 14:29:02,247 - Fetching 1 objects...
2023-09-03 14:29:02,248 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#203'.
2023-09-03 14:29:02,347 - Fetching 1 objects...
2023-09-03 14:29:02,348 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#204'.
2023-09-03 14:29:02,402 - Fetching 1 objects...
2023-09-03 14:29:02,403 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#207'.
2023-09-03 14:29:02,502 - Fetching 1 objects...
2023-09-03 14:29:02,504 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#208'.
2023-09-03 14:29:02,603 - Fetching 1 objects...
2023-09-03 14:29:02,604 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#209'.
2023-09-03 14:29:02,658 - Fetching 1 objects...
2023-09-03 14:29:02,659 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#210'.
2023-09-03 14:29:02,757 - Fetching 1 objects...
2023-09-03 14:29:02,758 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#211'.
2023-09-03 14:29:02,859 - Fetching 1 objects...
2023-09-03 14:29:02,860 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#212'.
2023-09-03 14:29:02,961 - Fetching 1 objects...
2023-09-03 14:29:02,963 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#213'.
2023-09-03 14:29:03,064 - Fetching 1 objects...
2023-09-03 14:29:03,065 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#214'.
2023-09-03 14:29:03,166 - Fetching 1 objects...
2023-09-03 14:29:03,167 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#215'.
2023-09-03 14:29:03,223 - Fetching 1 objects...
2023-09-03 14:29:03,223 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#216'.
2023-09-03 14:29:03,320 - Fetching 1 objects...
2023-09-03 14:29:03,321 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#217'.
2023-09-03 14:29:03,379 - Fetching 1 objects...
2023-09-03 14:29:03,379 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#219'.
2023-09-03 14:29:03,474 - Fetching 1 objects...
2023-09-03 14:29:03,474 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#218'.
2023-09-03 14:29:03,528 - Fetching 1 objects...
2023-09-03 14:29:03,529 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#220'.
2023-09-03 14:29:03,628 - Fetching 1 objects...
2023-09-03 14:29:03,629 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#221'.
2023-09-03 14:29:03,682 - Fetching 1 objects...
2023-09-03 14:29:03,683 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#222'.
2023-09-03 14:29:03,781 - Fetching 1 objects...
2023-09-03 14:29:03,781 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#223'.
2023-09-03 14:29:03,836 - Fetching 1 objects...
2023-09-03 14:29:03,837 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#224'.
2023-09-03 14:29:03,986 - Fetching 1 objects...
2023-09-03 14:29:03,986 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#225'.
2023-09-03 14:29:04,041 - Fetching 1 objects...
2023-09-03 14:29:04,042 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#226'.
2023-09-03 14:29:04,142 - Fetching 1 objects...
2023-09-03 14:29:04,143 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#227'.
2023-09-03 14:29:04,242 - Fetching 1 objects...
2023-09-03 14:29:04,243 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#228'.
2023-09-03 14:29:04,298 - Fetching 1 objects...
2023-09-03 14:29:04,299 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#229'.
2023-09-03 14:29:04,395 - Fetching 1 objects...
2023-09-03 14:29:04,396 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#230'.
2023-09-03 14:29:04,452 - Fetching 1 objects...
2023-09-03 14:29:04,453 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#231'.
2023-09-03 14:29:04,552 - Fetching 1 objects...
2023-09-03 14:29:04,553 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#232'.
2023-09-03 14:29:04,652 - Fetching 1 objects...
2023-09-03 14:29:04,653 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#233'.
2023-09-03 14:29:04,709 - Fetching 1 objects...
2023-09-03 14:29:04,709 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#234'.
2023-09-03 14:29:04,805 - Fetching 1 objects...
2023-09-03 14:29:04,805 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#235'.
2023-09-03 14:29:04,860 - Fetching 1 objects...
2023-09-03 14:29:04,861 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#236'.
2023-09-03 14:29:04,961 - Fetching 1 objects...
2023-09-03 14:29:04,962 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#237'.
2023-09-03 14:29:05,062 - Fetching 1 objects...
2023-09-03 14:29:05,063 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#238'.
2023-09-03 14:29:05,121 - Fetching 1 objects...
2023-09-03 14:29:05,121 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#239'.
2023-09-03 14:29:05,214 - Fetching 1 objects...
2023-09-03 14:29:05,215 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#240'.
2023-09-03 14:29:05,271 - Fetching 1 objects...
2023-09-03 14:29:05,272 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#241'.
2023-09-03 14:29:05,369 - Fetching 1 objects...
2023-09-03 14:29:05,370 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#242'.
2023-09-03 14:29:05,429 - Fetching 1 objects...
2023-09-03 14:29:05,430 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#244'.
2023-09-03 14:29:05,521 - Fetching 1 objects...
2023-09-03 14:29:05,522 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#245'.
2023-09-03 14:29:05,579 - Fetching 1 objects...
2023-09-03 14:29:05,579 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#246'.
2023-09-03 14:29:05,677 - Fetching 1 objects...
2023-09-03 14:29:05,677 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#247'.
2023-09-03 14:29:05,732 - Fetching 1 objects...
2023-09-03 14:29:05,733 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#248'.
2023-09-03 14:29:05,829 - Fetching 1 objects...
2023-09-03 14:29:05,829 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#249'.
2023-09-03 14:29:05,884 - Fetching 1 objects...
2023-09-03 14:29:05,885 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#250'.
2023-09-03 14:29:05,985 - Fetching 1 objects...
2023-09-03 14:29:05,986 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#251'.
2023-09-03 14:29:06,040 - Fetching 1 objects...
2023-09-03 14:29:06,041 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#252'.
2023-09-03 14:29:06,136 - Fetching 1 objects...
2023-09-03 14:29:06,137 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#253'.
2023-09-03 14:29:06,192 - Fetching 1 objects...
2023-09-03 14:29:06,193 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#254'.
2023-09-03 14:29:06,290 - Fetching 1 objects...
2023-09-03 14:29:06,291 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#255'.
2023-09-03 14:29:06,347 - Fetching 1 objects...
2023-09-03 14:29:06,348 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#256'.
2023-09-03 14:29:06,445 - Fetching 1 objects...
2023-09-03 14:29:06,446 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#257'.
2023-09-03 14:29:06,546 - Fetching 1 objects...
2023-09-03 14:29:06,547 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#258'.
2023-09-03 14:29:06,648 - Fetching 1 objects...
2023-09-03 14:29:06,648 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#259'.
2023-09-03 14:29:06,704 - Fetching 1 objects...
2023-09-03 14:29:06,705 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#265'.
2023-09-03 14:29:06,852 - Fetching 1 objects...
2023-09-03 14:29:06,853 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#266'.
2023-09-03 14:29:06,908 - Fetching 1 objects...
2023-09-03 14:29:06,908 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#275'.
2023-09-03 14:29:07,008 - Fetching 1 objects...
2023-09-03 14:29:07,009 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#276'.
2023-09-03 14:29:07,066 - Fetching 1 objects...
2023-09-03 14:29:07,067 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#277'.
2023-09-03 14:29:07,160 - Fetching 1 objects...
2023-09-03 14:29:07,161 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#278'.
2023-09-03 14:29:07,216 - Fetching 1 objects...
2023-09-03 14:29:07,216 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#382'.
2023-09-03 14:29:07,314 - Fetching 1 objects...
2023-09-03 14:29:07,315 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#383'.
2023-09-03 14:29:07,375 - Fetching 1 objects...
2023-09-03 14:29:07,375 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#384'.
2023-09-03 14:29:07,468 - Fetching 1 objects...
2023-09-03 14:29:07,468 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#463'.
2023-09-03 14:29:07,569 - Fetching 1 objects...
2023-09-03 14:29:07,570 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#386'.
2023-09-03 14:29:07,624 - Fetching 1 objects...
2023-09-03 14:29:07,624 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#387'.
2023-09-03 14:29:07,724 - Fetching 1 objects...
2023-09-03 14:29:07,725 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#388'.
2023-09-03 14:29:07,780 - Fetching 1 objects...
2023-09-03 14:29:07,781 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#389'.
2023-09-03 14:29:07,877 - Fetching 1 objects...
2023-09-03 14:29:07,878 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#390'.
2023-09-03 14:29:07,933 - Fetching 1 objects...
2023-09-03 14:29:07,933 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#391'.
2023-09-03 14:29:08,044 - Fetching 1 objects...
2023-09-03 14:29:08,044 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#394'.
2023-09-03 14:29:08,135 - Fetching 1 objects...
2023-09-03 14:29:08,136 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#395'.
2023-09-03 14:29:08,192 - Fetching 1 objects...
2023-09-03 14:29:08,193 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#397'.
2023-09-03 14:29:08,286 - Fetching 1 objects...
2023-09-03 14:29:08,287 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#398'.
2023-09-03 14:29:08,342 - Fetching 1 objects...
2023-09-03 14:29:08,343 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#399'.
2023-09-03 14:29:08,442 - Fetching 1 objects...
2023-09-03 14:29:08,464 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#400'.
2023-09-03 14:29:08,532 - Fetching 1 objects...
2023-09-03 14:29:08,533 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#401'.
2023-09-03 14:29:08,596 - Fetching 1 objects...
2023-09-03 14:29:08,596 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#402'.
2023-09-03 14:29:08,696 - Fetching 1 objects...
2023-09-03 14:29:08,697 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#403'.
2023-09-03 14:29:08,799 - Fetching 1 objects...
2023-09-03 14:29:08,799 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#404'.
2023-09-03 14:29:08,898 - Fetching 1 objects...
2023-09-03 14:29:08,899 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#405'.
2023-09-03 14:29:08,954 - Fetching 1 objects...
2023-09-03 14:29:08,955 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#406'.
2023-09-03 14:29:09,008 - Fetching 1 objects...
2023-09-03 14:29:09,009 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#407'.
2023-09-03 14:29:09,105 - Fetching 1 objects...
2023-09-03 14:29:09,106 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#408'.
2023-09-03 14:29:09,195 - Fetching 1 objects...
2023-09-03 14:29:09,196 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#410'.
2023-09-03 14:29:09,252 - Fetching 1 objects...
2023-09-03 14:29:09,252 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#411'.
2023-09-03 14:29:09,311 - Fetching 1 objects...
2023-09-03 14:29:09,311 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#412'.
2023-09-03 14:29:09,412 - Fetching 1 objects...
2023-09-03 14:29:09,413 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#414'.
2023-09-03 14:29:09,515 - Fetching 1 objects...
2023-09-03 14:29:09,516 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#419'.
2023-09-03 14:29:09,617 - Fetching 1 objects...
2023-09-03 14:29:09,618 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#420'.
2023-09-03 14:29:09,720 - Fetching 1 objects...
2023-09-03 14:29:09,721 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#421'.
2023-09-03 14:29:09,783 - Fetching 1 objects...
2023-09-03 14:29:09,783 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#422'.
2023-09-03 14:29:09,932 - Fetching 1 objects...
2023-09-03 14:29:09,933 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#424'.
2023-09-03 14:29:09,996 - Fetching 1 objects...
2023-09-03 14:29:09,997 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#425'.
2023-09-03 14:29:10,054 - Fetching 1 objects...
2023-09-03 14:29:10,054 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#427'.
2023-09-03 14:29:10,132 - Fetching 1 objects...
2023-09-03 14:29:10,133 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#426'.
2023-09-03 14:29:10,262 - Fetching 1 objects...
2023-09-03 14:29:10,263 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#428'.
2023-09-03 14:29:10,336 - Fetching 1 objects...
2023-09-03 14:29:10,337 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#429'.
2023-09-03 14:29:10,402 - Fetching 1 objects...
2023-09-03 14:29:10,403 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#430'.
2023-09-03 14:29:10,458 - Fetching 1 objects...
2023-09-03 14:29:10,459 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#431'.
2023-09-03 14:29:10,541 - Fetching 1 objects...
2023-09-03 14:29:10,542 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#453'.
2023-09-03 14:29:10,645 - Fetching 1 objects...
2023-09-03 14:29:10,645 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#469'.
2023-09-03 14:29:10,746 - Fetching 1 objects...
2023-09-03 14:29:10,747 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#470'.
2023-09-03 14:29:10,847 - Fetching 1 objects...
2023-09-03 14:29:10,848 - Fetching object with key: '{NHibernate-Cache:lookups}-1:Entities.LookupGroup#475'.
2023-09-03 14:29:10,949 - loading entity: [Entities.LookupGroup#2]
2023-09-03 14:29:10,950 - Opened new DbCommand, open DbCommands: 2
Maybe that key is locked in Redis that's why it reports missed cache? @fredericDelaporte, can you please check it as it kills the application. And why does it load all other LookupGroup keys not just that 25 ones?
Btw, I can see those keys inside Redis.
Here is the log file
LookupGroup Debug.zip
fredericDelaporte commented
It is hard to reproduce and debug a trouble only from debug logs. That is was I was asking if you can reproduce it with the test project.
For Redis, the test project is here, but better clone the whole repository, it has dependencies.
Cache tests currently are done without actually using NHibernate. Your trouble may require using NHibernate to be reproduced. In such case you may have it easier to write a test within the NHibernate test project, see Contributing for getting started with it.
Btw, how could it be specific to my application?
It could be a special case of settings used by your application which triggers the trouble, or whatever. The Redis Cache provider NuGet has got around 300 000 downloads since it enabled batching by default. So, your trouble does not look to be a systematic one, but one that needs special conditions to be triggered.
Without a reliable way for contributors to reproduce the trouble, we will likely not be able to fix it, if that is a trouble in NHibernate or the cache provider.
By the way, I thought there was a note of you somewhere about the Redis client version being outdated, but I am not finding it. If that is a concern to you, the cache provider simply states the minimal version of the Redis client with which it is compatible. If you want a more recent one, simply add it as a dependency of your application. Here are detailed explanations about this.
EngSayed commented
One enhancement which could be done, after checking SLC and find it is missed then it goes to DB DefaultLoadEventListener.LoadFromDatasource then it should not go again trying to fetch from cache, right?
EngSayed commented
@fredericDelaporte, the logs should help understanding the pattern which is occurring by tracking the logs I could see that it could not find the keys inside Redis for some reason!
What could be the reason for such behavior? especially keep trying to load many keys even more than 25 in the batch.
I am not sure if I would be able to create that test which you are asking me for. Also as I mentioned this issue does not occur when I run each application separately, it only happens when the 2 applications run at the same time
EngSayed commented
From the logs I can see that after calling GetMany then it calls GetValue which logs that the cached item was locked and this is the main issue.
2023-09-03 14:28:20,414 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#1
2023-09-03 14:28:20,415 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#2
2023-09-03 14:28:20,416 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#3
2023-09-03 14:28:20,417 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#4
2023-09-03 14:28:20,417 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#5
2023-09-03 14:28:20,418 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#6
2023-09-03 14:28:20,419 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#8
2023-09-03 14:28:20,419 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#9
2023-09-03 14:28:20,420 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#10
2023-09-03 14:28:20,421 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#7
2023-09-03 14:28:20,421 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#11
2023-09-03 14:28:20,422 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#12
2023-09-03 14:28:20,423 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#13
2023-09-03 14:28:20,424 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#14
2023-09-03 14:28:20,426 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#15
2023-09-03 14:28:20,427 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#16
2023-09-03 14:28:20,429 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#17
2023-09-03 14:28:20,430 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#18
2023-09-03 14:28:20,430 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#462
2023-09-03 14:28:20,431 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#19
2023-09-03 14:28:20,432 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#20
2023-09-03 14:28:20,432 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#21
2023-09-03 14:28:20,433 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#22
2023-09-03 14:28:20,433 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#23
2023-09-03 14:28:20,434 - Cached item was locked: TRS.Flint.BLL.Entities.LookupGroup#24
2023-09-03 14:28:20,440 - Entity cache miss: TRS.Flint.BLL.Entities.LookupGroup#1
NHibernate.Cache.ReadWriteCache:
private static object GetValue(long timestamp, CacheKey key, ILockable lockable)
{
var gettable = lockable != null && lockable.IsGettable(timestamp);
if (gettable)
{
if (log.IsDebugEnabled())
{
log.Debug("Cache hit: {0}", key);
}
return ((CachedItem) lockable).Value;
}
if (log.IsDebugEnabled())
{
log.Debug(lockable == null ? "Cache miss: {0}" : "Cached item was locked: {0}", key);
}
return null;
}
So lockable is not null which means lockable.IsGettable(timestamp) returned false.
I see 2 concrete classes: CachedItem (It checkes the timestamp against some fresh time stamp) & CacheLock (it returns always false).
EngSayed commented
@fredericDelaporte, I have added a log to check how IsGettable returns false and here is the log:
CachedItem IsGettable: False - FreshTimestamp: 6937663858212864 - txTimestamp: 6937663715237888
So it seems CachedItem.IsGettable returns false because FreshTimestamp greater than txTimestamp.
My understanding is that you are trying to compare the timestamp when a CachedItem was created vs when session was created and if the CachedItem timestamp is greater then you believe that the key was locked before (or maybe updated, right?)
But what if the key was updated before because the session was created long time ago then why do not we get the last updated value from the cache?
I am not fully understanding this logic.
Also I see from the logs that first it returned true but after that it returned false so I am guessing there could be an issue in that IsGettable(...) logic.
EngSayed commented
@fredericDelaporte, I have removed that check return FreshTimestamp < txTimestamp; and just returned true ... now the 2 applications startup fine. I still do not understand the logic behind that check so can you please check it?
EngSayed commented
@fredericDelaporte, I believe I fixed the issue. There is function BatchFetchQueue.GetEntityBatch(IEntityPersister persister, object id, int batchSize, bool checkCache)
So we need to call this method with checkCache = false when the cache key is locked or missed. So when we call DefaultLoadEventListener.LoadFromDatasource(..) after finding the cache key is locked, we must create this flag to set checkCache to false and propagate this flag till GetEntityBatch()
This makes sure that we do not try to call the cache again when we find out the cache is missed or locked and it prevents that strange behavior.
fredericDelaporte commented
Are you using transactions around queries using the cache? If no, it can work correctly. I am thinking about it because of the timestamp: that is typically what occurs when not using transactions. See the documentation:
The second level cache requires the use of transactions, be it through transaction scopes or NHibernate transactions. Interacting with the data store without an explicit transaction is discouraged, and will not allow the second level cache to work as intended.
EngSayed commented
Are you using transactions around queries using the cache? If no, it can work correctly. I am thinking about it because of the timestamp: that is typically what occurs when not using transactions. See the documentation:
The second level cache requires the use of transactions, be it through transaction scopes or NHibernate transactions. Interacting with the data store without an explicit transaction is discouraged, and will not allow the second level cache to work as intended.
Yes, I am using transactions around queries.
EngSayed commented
@fredericDelaporte did you check all my comments?
The timestamp difference is probably because another application updated the key (if I understand the logic well)
And I believe the main issue happens when the code report that the key is locked and then calls LoadFromDatasource to load from DB, But still it tries to check the cache which is wrong IMHO. So the fix should be pass a flag to not check cache. Please check my comments above
EngSayed commented
@fredericDelaporte, any updates please?
fredericDelaporte commented
Nope, no time available.
EngSayed commented
@fredericDelaporte, please have a look into those changes
nhibernate/nhibernate-core@master...EngSayed:nhibernate-core-concurrency-issue:master
fredericDelaporte commented
You're welcome to contribute,
Doing so through a PR is easier for review. Can you issue a PR?
Please also check contributing.
It seems you change a public API: in such case the change would have to wait a new major version, or you should do it while preserving the current API. (Like, obsolete the previous method, add a new one. If changing an interface, even adding a method is a breaking change and would require a new version. So instead we use extension methods with TODO comments for merging them in the interface on the next major version.
dplaskon commented
@EngSayed - you're not alone. We too, are seeing this behavior in production, and it is most worrisome.
@fredericDelaporte - I might be missing something, but is there no way, via configuration to disable PreferMultipleGet with this provider? If there isn't, what is a workable option to avoid using this behavior?
dplaskon commented
Ok, answering my own question here.
Overridding RedisCache and RedisCacheProvider is the way to do this, so I'll be giving that a shot as a temporary solution.
This is an aside from the original issue, but making this configurable in the future may be a good idea.