-
Notifications
You must be signed in to change notification settings - Fork 159
/
ConcurrencyUtil.java
1692 lines (1558 loc) · 113 KB
/
ConcurrencyUtil.java
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
416
417
418
419
420
421
422
423
424
425
426
427
428
429
430
431
432
433
434
435
436
437
438
439
440
441
442
443
444
445
446
447
448
449
450
451
452
453
454
455
456
457
458
459
460
461
462
463
464
465
466
467
468
469
470
471
472
473
474
475
476
477
478
479
480
481
482
483
484
485
486
487
488
489
490
491
492
493
494
495
496
497
498
499
500
501
502
503
504
505
506
507
508
509
510
511
512
513
514
515
516
517
518
519
520
521
522
523
524
525
526
527
528
529
530
531
532
533
534
535
536
537
538
539
540
541
542
543
544
545
546
547
548
549
550
551
552
553
554
555
556
557
558
559
560
561
562
563
564
565
566
567
568
569
570
571
572
573
574
575
576
577
578
579
580
581
582
583
584
585
586
587
588
589
590
591
592
593
594
595
596
597
598
599
600
601
602
603
604
605
606
607
608
609
610
611
612
613
614
615
616
617
618
619
620
621
622
623
624
625
626
627
628
629
630
631
632
633
634
635
636
637
638
639
640
641
642
643
644
645
646
647
648
649
650
651
652
653
654
655
656
657
658
659
660
661
662
663
664
665
666
667
668
669
670
671
672
673
674
675
676
677
678
679
680
681
682
683
684
685
686
687
688
689
690
691
692
693
694
695
696
697
698
699
700
701
702
703
704
705
706
707
708
709
710
711
712
713
714
715
716
717
718
719
720
721
722
723
724
725
726
727
728
729
730
731
732
733
734
735
736
737
738
739
740
741
742
743
744
745
746
747
748
749
750
751
752
753
754
755
756
757
758
759
760
761
762
763
764
765
766
767
768
769
770
771
772
773
774
775
776
777
778
779
780
781
782
783
784
785
786
787
788
789
790
791
792
793
794
795
796
797
798
799
800
801
802
803
804
805
806
807
808
809
810
811
812
813
814
815
816
817
818
819
820
821
822
823
824
825
826
827
828
829
830
831
832
833
834
835
836
837
838
839
840
841
842
843
844
845
846
847
848
849
850
851
852
853
854
855
856
857
858
859
860
861
862
863
864
865
866
867
868
869
870
871
872
873
874
875
876
877
878
879
880
881
882
883
884
885
886
887
888
889
890
891
892
893
894
895
896
897
898
899
900
901
902
903
904
905
906
907
908
909
910
911
912
913
914
915
916
917
918
919
920
921
922
923
924
925
926
927
928
929
930
931
932
933
934
935
936
937
938
939
940
941
942
943
944
945
946
947
948
949
950
951
952
953
954
955
956
957
958
959
960
961
962
963
964
965
966
967
968
969
970
971
972
973
974
975
976
977
978
979
980
981
982
983
984
985
986
987
988
989
990
991
992
993
994
995
996
997
998
999
1000
/*
* Copyright (c) 2021 Oracle, IBM and/or its affiliates. All rights reserved.
*
* This program and the accompanying materials are made available under the
* terms of the Eclipse Public License v. 2.0 which is available at
* http://www.eclipse.org/legal/epl-2.0,
* or the Eclipse Distribution License v. 1.0 which is available at
* http://www.eclipse.org/org/documents/edl-v10.php.
*
* SPDX-License-Identifier: EPL-2.0 OR BSD-3-Clause
*/
// Contributors:
// Oracle - initial API and implementation from Oracle TopLink
// IBM - ConcurrencyUtil call of ThreadMXBean.getThreadInfo() needs doPriv
package org.eclipse.persistence.internal.helper;
import org.eclipse.persistence.config.SystemProperties;
import org.eclipse.persistence.internal.helper.type.CacheKeyToThreadRelationships;
import org.eclipse.persistence.internal.helper.type.ConcurrencyManagerState;
import org.eclipse.persistence.internal.helper.type.DeadLockComponent;
import org.eclipse.persistence.internal.helper.type.ReadLockAcquisitionMetadata;
import org.eclipse.persistence.internal.identitymaps.CacheKey;
import org.eclipse.persistence.internal.localization.TraceLocalization;
import org.eclipse.persistence.internal.security.PrivilegedAccessHelper;
import org.eclipse.persistence.internal.security.PrivilegedGetSystemProperty;
import org.eclipse.persistence.internal.security.PrivilegedGetThreadInfo;
import org.eclipse.persistence.logging.AbstractSessionLog;
import org.eclipse.persistence.logging.SessionLog;
import java.io.StringWriter;
import java.lang.management.ManagementFactory;
import java.lang.management.ThreadInfo;
import java.lang.management.ThreadMXBean;
import java.security.AccessController;
import java.util.*;
import java.util.concurrent.atomic.AtomicLong;
public class ConcurrencyUtil {
public static final ConcurrencyUtil SINGLETON = new ConcurrencyUtil();
private static final long DEFAULT_ACQUIRE_WAIT_TIME = 0L;
private static final long DEFAULT_BUILD_OBJECT_COMPLETE_WAIT_TIME = 0L;
private static final long DEFAULT_MAX_ALLOWED_SLEEP_TIME_MS = 40000L;
private static final long DEFAULT_MAX_ALLOWED_FREQUENCY_TINY_DUMP_LOG_MESSAGE = 40000L;
private static final long DEFAULT_MAX_ALLOWED_FREQUENCY_MASSIVE_DUMP_LOG_MESSAGE = 60000L;
private static final boolean DEFAULT_INTERRUPTED_EXCEPTION_FIRED = true;
private static final boolean DEFAULT_CONCURRENCY_EXCEPTION_FIRED = true;
private static final boolean DEFAULT_TAKING_STACKTRACE_DURING_READ_LOCK_ACQUISITION = false;
public static final boolean DEFAULT_USE_SEMAPHORE_TO_SLOW_DOWN_OBJECT_BUILDING_CONCURRENCY = false;
public static final boolean DEFAULT_USE_SEMAPHORE_TO_SLOW_DOWN_WRITE_LOCK_MANAGER_ACQUIRE_REQUIRED_LOCKS = false;
public static final int DEFAULT_CONCURRENCY_MANAGER_OBJECT_BUILDING_NO_THREADS = 10;
public static final int DEFAULT_CONCURRENCY_MANAGER_WRITE_LOCK_MANAGER_ACQUIRE_REQUIRED_LOCKS_NO_THREADS = 2;
public static final long DEFAULT_CONCURRENCY_SEMAPHORE_MAX_TIME_PERMIT = 2000L;
public static final long DEFAULT_CONCURRENCY_SEMAPHORE_LOG_TIMEOUT = 10000L;
private long acquireWaitTime = getLongProperty(SystemProperties.CONCURRENCY_MANAGER_ACQUIRE_WAIT_TIME, DEFAULT_ACQUIRE_WAIT_TIME);
private long buildObjectCompleteWaitTime = getLongProperty(SystemProperties.CONCURRENCY_MANAGER_BUILD_OBJECT_COMPLETE_WAIT_TIME, DEFAULT_BUILD_OBJECT_COMPLETE_WAIT_TIME);
private long maxAllowedSleepTime = getLongProperty(SystemProperties.CONCURRENCY_MANAGER_MAX_SLEEP_TIME, DEFAULT_MAX_ALLOWED_SLEEP_TIME_MS);
private long maxAllowedFrequencyToProduceTinyDumpLogMessage = getLongProperty(SystemProperties.CONCURRENCY_MANAGER_MAX_FREQUENCY_DUMP_TINY_MESSAGE, DEFAULT_MAX_ALLOWED_FREQUENCY_TINY_DUMP_LOG_MESSAGE);
private long maxAllowedFrequencyToProduceMassiveDumpLogMessage = getLongProperty(SystemProperties.CONCURRENCY_MANAGER_MAX_FREQUENCY_DUMP_MASSIVE_MESSAGE, DEFAULT_MAX_ALLOWED_FREQUENCY_MASSIVE_DUMP_LOG_MESSAGE);
private boolean allowInterruptedExceptionFired = getBooleanProperty(SystemProperties.CONCURRENCY_MANAGER_ALLOW_INTERRUPTED_EXCEPTION, DEFAULT_INTERRUPTED_EXCEPTION_FIRED);
private boolean allowConcurrencyExceptionToBeFiredUp = getBooleanProperty(SystemProperties.CONCURRENCY_MANAGER_ALLOW_CONCURRENCY_EXCEPTION, DEFAULT_CONCURRENCY_EXCEPTION_FIRED);
private boolean allowTakingStackTraceDuringReadLockAcquisition = getBooleanProperty(SystemProperties.CONCURRENCY_MANAGER_ALLOW_STACK_TRACE_READ_LOCK, DEFAULT_TAKING_STACKTRACE_DURING_READ_LOCK_ACQUISITION);
private boolean useSemaphoreInObjectBuilder = getBooleanProperty(SystemProperties.CONCURRENCY_MANAGER_USE_SEMAPHORE_TO_SLOW_DOWN_OBJECT_BUILDING, DEFAULT_USE_SEMAPHORE_TO_SLOW_DOWN_OBJECT_BUILDING_CONCURRENCY);
private boolean useSemaphoreToLimitConcurrencyOnWriteLockManagerAcquireRequiredLocks = getBooleanProperty(SystemProperties.CONCURRENCY_MANAGER_USE_SEMAPHORE_TO_SLOW_DOWN_WRITE_LOCK_MANAGER_ACQUIRE_REQUIRED_LOCKS, DEFAULT_USE_SEMAPHORE_TO_SLOW_DOWN_WRITE_LOCK_MANAGER_ACQUIRE_REQUIRED_LOCKS);
private int noOfThreadsAllowedToObjectBuildInParallel = getIntProperty(SystemProperties.CONCURRENCY_MANAGER_OBJECT_BUILDING_NO_THREADS, DEFAULT_CONCURRENCY_MANAGER_OBJECT_BUILDING_NO_THREADS);
private int noOfThreadsAllowedToDoWriteLockManagerAcquireRequiredLocksInParallel = getIntProperty(SystemProperties.CONCURRENCY_MANAGER_WRITE_LOCK_MANAGER_ACQUIRE_REQUIRED_LOCKS_NO_THREADS, DEFAULT_CONCURRENCY_MANAGER_WRITE_LOCK_MANAGER_ACQUIRE_REQUIRED_LOCKS_NO_THREADS);
private long concurrencySemaphoreMaxTimePermit = getLongProperty(SystemProperties.CONCURRENCY_SEMAPHORE_MAX_TIME_PERMIT, DEFAULT_CONCURRENCY_SEMAPHORE_MAX_TIME_PERMIT);
private long concurrencySemaphoreLogTimeout = getLongProperty(SystemProperties.CONCURRENCY_SEMAPHORE_LOG_TIMEOUT, DEFAULT_CONCURRENCY_SEMAPHORE_LOG_TIMEOUT);
/**
* Thread local variable that allows the current thread to know when was the last time that this specific thread
* produced the "tiny dump" indicating that the thread is stuck.
*/
private final ThreadLocal<Date> threadLocalDateWhenCurrentThreadLastComplainedAboutBeingStuckInDeadLock = new ThreadLocal<>();
/**
* Whenever we produce a tiny dump log message we will give it a unit identifier
*/
private final AtomicLong currentTinyMessageLogDumpNumber = new AtomicLong(0);
/**
* Whenever we produce a massive dump log message we will give it a unit identifier
*/
private final AtomicLong currentMassiveDumpMessageLogDumpNumber = new AtomicLong(0);
private final Object dateWhenLastConcurrencyManagerStateFullDumpWasPerformedLock = new Object();
/**
* Whenever we decide to log a massive dump of the state of the concurrency manager we need to make this date move forward.
* <P>
* This variable is telling any thread that might be considering the possibility of logging a massive dump log message,
* when a massive dump was last performed, thus allowing threads to avoid spamming too much.
*
* <P>
* NOTE: <br>
* Needs to be accessed in a synchronized method.
*/
private long dateWhenLastConcurrencyManagerStateFullDumpWasPerformed = 0L;
/**
* When we are explaining where read locks were acquired, the first time we see a new stack trace we create a stack
* trace id. Then for all other read locks we just say in the massive please go have a look at stack trace xxx.
*/
private final AtomicLong stackTraceIdAtomicLong = new AtomicLong(0);
private ConcurrencyUtil() {
}
/**
* Throw an interrupted exception if appears that eclipse link code is taking too long to release a deferred lock.
*
* @param whileStartTimeMillis
* the start date of the while tru loop for releasing a deferred lock
* @param callerIsWillingToAllowInterruptedExceptionToBeFiredUpIfNecessary
* this flag is to allow the write lock manager to say that it is afraid of a concurrency exception being
* fire up because the thread in a dead lock might be trying to do a commit and blowing these threads up
* is most likely too dangerous and possibly the eclipselink code is not robust enough to code with such
* scenarios We do not care so much about blowing up exception during object building but during
* committing of transactions we are very afraid
* @throws InterruptedException
* we fire an interrupted exception to ensure that the code blows up and releases all of the locks it
* had.
*/
public void determineIfReleaseDeferredLockAppearsToBeDeadLocked(ConcurrencyManager concurrencyManager,
final long whileStartTimeMillis, DeferredLockManager lockManager, ReadLockManager readLockManager,
boolean callerIsWillingToAllowInterruptedExceptionToBeFiredUpIfNecessary)
throws InterruptedException {
// (a) Determine if we believe to be dealing with a dead lock
final long maxAllowedSleepTimeMillis = ConcurrencyUtil.SINGLETON.getMaxAllowedSleepTime();
long whileCurrentTimeMillis = System.currentTimeMillis();
long elapsedTime = whileCurrentTimeMillis - whileStartTimeMillis;
boolean tooMuchTimeHasElapsed = tooMuchTimeHasElapsed(whileStartTimeMillis, maxAllowedSleepTimeMillis);
if (!tooMuchTimeHasElapsed) {
// this thread is not stuck for that long let us allow the code to continue waiting for the lock to be acquired
// or for the deferred locks to be considered as finished
return;
}
// (b) We believe this is a dead lock
// before we start spamming the server log lets make sure this thread has not spammed the server log too recently
if(threadLocalDateWhenCurrentThreadLastComplainedAboutBeingStuckInDeadLock.get() == null) {
// make sure the thread local variable never returns null
threadLocalDateWhenCurrentThreadLastComplainedAboutBeingStuckInDeadLock.set(new Date(0));
}
Date dateWhenTinyCurrentThreadBeingStuckMessageWasLastLogged = threadLocalDateWhenCurrentThreadLastComplainedAboutBeingStuckInDeadLock.get();
final long maxAllowedFrequencyToDumpTinyMessage = getMaxAllowedFrequencyToProduceTinyDumpLogMessage();
boolean tooMuchTimeHasElapsedSinceLastLoggingOfTinyMessage = tooMuchTimeHasElapsed(dateWhenTinyCurrentThreadBeingStuckMessageWasLastLogged.getTime(), maxAllowedFrequencyToDumpTinyMessage);
if(!tooMuchTimeHasElapsedSinceLastLoggingOfTinyMessage) {
// this thread has recently logged a small message about the fact that it is stuck
// no point in logging another message like that for some time
// let us allow for this thread to silently continue stuck without logging anything
return ;
}
// (c) This thread it is dead lock since the whileStartDate indicates a dead lock and
// this thread has been keeping silent about the problem for some time since the dateWhenTinyCurrentThreadBeingStuckMessageWasLastLogged
// indicates that quite some time has elapsed since we have last spammed the server log
// we now start by spamming into the server log a "tiny message" specific to the current thread
String tinyErrorMessage = currentThreadIsStuckForSomeTimeProduceTinyLogMessage(elapsedTime, concurrencyManager, lockManager, readLockManager);
// (d) next step is to log into the server log the massive dump log message where we try to explaing the concrrency mangaer state
// only one thread will suceed in doing the massive dump ever 1 minute or so
// we do not want that a massive dump is log all the time
dumpConcurrencyManagerInformationIfAppropriate();
// (e) Finaly we need to check what the user wants us to when we decide that we are in the middle of a dead lock
// and we have dumped whatever information we could dump
// does the user want us to blow up the thread to try release acquired locks and allow other threads to move forward
// or is the user afraid that we fire up a thread interrupted exception because if the dead lock does not resolve
// production will be serously affect by aborted business process that should normally have suceeded and after N rerties
// (e.g. 3 jms MDB message retries) the process is aborted as failed making live system recovery extermelly difficult?
// the project must decide how to forward here...
// a frozen system seems for the time being the safest course of action
// because the interrupted exception might be leaving the cocurrency manager corrupted in terms f the cache keys and the readers on the cache keys
// NOTE:
// This project has reported that our blowing up of the JTA transaction
// to release the dead lock is not being 100% effective the system can still freeze forever
// And if interrupting the thread and releasing its resources is not effective
// then we are worse off.
// Best is to leave the system frozen and simply spam into the log of the server
// the current state of cache
boolean allowConcurrencyExceptionToBeFiredUp = isAllowConcurrencyExceptionToBeFiredUp();
if (allowConcurrencyExceptionToBeFiredUp) {
// The first check if in general concurrency excpetions to resolve the dead locks can be fired is passed
// but we do one final check. The WriteLockManager is afraid of seing its thread being blown up
// so the write lock manager will be prohibiting this exception from being fired up
if (callerIsWillingToAllowInterruptedExceptionToBeFiredUpIfNecessary) {
throw new InterruptedException(tinyErrorMessage);
}
} else {
AbstractSessionLog.getLog().log(SessionLog.SEVERE, SessionLog.CACHE,"concurrency_manager_allow_concurrency_exception_fired_up");
}
}
/**
* @return "eclipselink.concurrency.manager.waittime" persistence property value.
*/
public long getAcquireWaitTime() {
return this.acquireWaitTime;
}
public void setAcquireWaitTime(long acquireWaitTime) {
this.acquireWaitTime = acquireWaitTime;
}
/**
* @return "eclipselink.concurrency.manager.build.object.complete.waittime" persistence property value.
*/
public long getBuildObjectCompleteWaitTime() {
return buildObjectCompleteWaitTime;
}
public void setBuildObjectCompleteWaitTime(long buildObjectCompleteWaitTime) {
this.buildObjectCompleteWaitTime = buildObjectCompleteWaitTime;
}
/**
* @return property to control how long we are willing to wait before firing up an exception
*/
public long getMaxAllowedSleepTime() {
return this.maxAllowedSleepTime;
}
public void setMaxAllowedSleepTime(long maxAllowedSleepTime) {
this.maxAllowedSleepTime = maxAllowedSleepTime;
}
/**
* Just like we have a massive dump log message see {@link #getMaxAllowedFrequencyToProduceMassiveDumpLogMessage()}
* we also want threads to produce "tiny" dump about the fact that they rae stuck. We want to avoid these threads
* spaming too much the server log ... once the log message is out there not much point in continuously pumping the
* same log message out over and over again. Controlling how frequently the tiny dump is important especially when
* the user configures the hacked eclipselink to not fire up a blow up exception and instead to allow eclipselink to
* remain frozen forever.
*
* @return the frequency with which we are allowed to create a tiny dump log message
*/
public long getMaxAllowedFrequencyToProduceTinyDumpLogMessage() {
return this.maxAllowedFrequencyToProduceTinyDumpLogMessage;
}
public void setMaxAllowedFrequencyToProduceTinyDumpLogMessage(long maxAllowedFrequencyToProduceTinyDumpLogMessage) {
this.maxAllowedFrequencyToProduceTinyDumpLogMessage = maxAllowedFrequencyToProduceTinyDumpLogMessage;
}
/**
* If the system is perceived to be frozen and not evolving any longer, we will allow that every so often (e.g. once
* a minute) the logic complaining that the thread is stuck and going nowhere logs a very big dump message where the
* FULL concurrency manager state is explained. So that we can (manually) try to understand the dead lock based on
* the dumped information
*
* See also {@link #dateWhenLastConcurrencyManagerStateFullDumpWasPerformed}.
*/
public long getMaxAllowedFrequencyToProduceMassiveDumpLogMessage() {
return this.maxAllowedFrequencyToProduceMassiveDumpLogMessage;
}
public void setMaxAllowedFrequencyToProduceMassiveDumpLogMessage(long maxAllowedFrequencyToProduceMassiveDumpLogMessage) {
this.maxAllowedFrequencyToProduceMassiveDumpLogMessage = maxAllowedFrequencyToProduceMassiveDumpLogMessage;
}
public boolean isAllowInterruptedExceptionFired() {
return this.allowInterruptedExceptionFired;
}
public void setAllowInterruptedExceptionFired(boolean allowInterruptedExceptionFired) {
this.allowInterruptedExceptionFired = allowInterruptedExceptionFired;
}
/**
* @return true if we are supposed to be firing up exception to abort the thread in a dead lock, false we are afraid
* of trying to abort the transaction and not managing to resolve the dead lock and prefer to system frozen
* and be forced into restarting it.
*/
public boolean isAllowConcurrencyExceptionToBeFiredUp() {
return this.allowConcurrencyExceptionToBeFiredUp;
}
public void setAllowConcurrencyExceptionToBeFiredUp(boolean allowConcurrencyExceptionToBeFiredUp) {
this.allowConcurrencyExceptionToBeFiredUp = allowConcurrencyExceptionToBeFiredUp;
}
public boolean isAllowTakingStackTraceDuringReadLockAcquisition() {
return this.allowTakingStackTraceDuringReadLockAcquisition;
}
public void setAllowTakingStackTraceDuringReadLockAcquisition(boolean allowTakingStackTraceDuringReadLockAcquisition) {
this.allowTakingStackTraceDuringReadLockAcquisition = allowTakingStackTraceDuringReadLockAcquisition;
}
public boolean isUseSemaphoreInObjectBuilder() {
return useSemaphoreInObjectBuilder;
}
public void setUseSemaphoreInObjectBuilder(boolean useSemaphoreInObjectBuilder) {
this.useSemaphoreInObjectBuilder = useSemaphoreInObjectBuilder;
}
public boolean isUseSemaphoreToLimitConcurrencyOnWriteLockManagerAcquireRequiredLocks() {
return useSemaphoreToLimitConcurrencyOnWriteLockManagerAcquireRequiredLocks;
}
public void setUseSemaphoreToLimitConcurrencyOnWriteLockManagerAcquireRequiredLocks(boolean useSemaphoreToLimitConcurrencyOnWriteLockManagerAcquireRequiredLocks) {
this.useSemaphoreToLimitConcurrencyOnWriteLockManagerAcquireRequiredLocks = useSemaphoreToLimitConcurrencyOnWriteLockManagerAcquireRequiredLocks;
}
public int getNoOfThreadsAllowedToObjectBuildInParallel() {
return noOfThreadsAllowedToObjectBuildInParallel;
}
public void setNoOfThreadsAllowedToObjectBuildInParallel(int noOfThreadsAllowedToObjectBuildInParallel) {
this.noOfThreadsAllowedToObjectBuildInParallel = noOfThreadsAllowedToObjectBuildInParallel;
}
public int getNoOfThreadsAllowedToDoWriteLockManagerAcquireRequiredLocksInParallel() {
return noOfThreadsAllowedToDoWriteLockManagerAcquireRequiredLocksInParallel;
}
public void setNoOfThreadsAllowedToDoWriteLockManagerAcquireRequiredLocksInParallel(int noOfThreadsAllowedToDoWriteLockManagerAcquireRequiredLocksInParallel) {
this.noOfThreadsAllowedToDoWriteLockManagerAcquireRequiredLocksInParallel = noOfThreadsAllowedToDoWriteLockManagerAcquireRequiredLocksInParallel;
}
public long getConcurrencySemaphoreMaxTimePermit() {
return concurrencySemaphoreMaxTimePermit;
}
public void setConcurrencySemaphoreMaxTimePermit(long concurrencySemaphoreMaxTimePermit) {
this.concurrencySemaphoreMaxTimePermit = concurrencySemaphoreMaxTimePermit;
}
public long getConcurrencySemaphoreLogTimeout() {
return concurrencySemaphoreLogTimeout;
}
public void setConcurrencySemaphoreLogTimeout(long concurrencySemaphoreLogTimeout) {
this.concurrencySemaphoreLogTimeout = concurrencySemaphoreLogTimeout;
}
/**
*
* @return A to string of the cache key (e.g. that we are trying to lock
*/
public String createToStringExplainingOwnedCacheKey(ConcurrencyManager concurrencyManager) {
String cacheKeyClass = concurrencyManager.getClass().getCanonicalName();
Thread activeThreadObj = concurrencyManager.getActiveThread();
String activeThread = activeThreadObj != null ? activeThreadObj.getName() : "Null";
long concurrencyManagerId = concurrencyManager.getConcurrencyManagerId();
Date concurrencyManagerCreationDate = concurrencyManager.getConcurrencyManagerCreationDate();
if (concurrencyManager instanceof CacheKey) {
CacheKey cacheKey = (CacheKey) concurrencyManager;
Object primaryKey = cacheKey.getKey();
Object cacheKeyObject = cacheKey.getObject();
String canonicalName = cacheKeyObject != null ? cacheKeyObject.getClass().getCanonicalName()
: TraceLocalization.buildMessage("concurrency_util_owned_cache_key_null");
return TraceLocalization.buildMessage("concurrency_util_owned_cache_key_is_cache_key", new Object[] {canonicalName, primaryKey,
cacheKeyObject, String.valueOf(System.identityHashCode(cacheKeyObject)),
cacheKeyClass, String.valueOf(System.identityHashCode(cacheKey)),
activeThread, concurrencyManager.getNumberOfReaders(), concurrencyManagerId,
ConversionManager.getDefaultManager().convertObject(concurrencyManagerCreationDate, String.class).toString(),
// metadata of number of times the cache key suffered increases in number readers
cacheKey.getTotalNumberOfKeysAcquiredForReading(),
cacheKey.getTotalNumberOfKeysReleasedForReading(),
cacheKey.getTotalNumberOfKeysReleasedForReadingBlewUpExceptionDueToCacheKeyHavingReachedCounterZero(),
concurrencyManager.getDepth()});
} else {
return TraceLocalization.buildMessage("concurrency_util_owned_cache_key_is_not_cache_key", new Object[] {cacheKeyClass, concurrencyManager, activeThread,
concurrencyManagerId, ConversionManager.getDefaultManager().convertObject(concurrencyManagerCreationDate, String.class).toString(),
concurrencyManager.getTotalNumberOfKeysAcquiredForReading(),
concurrencyManager.getTotalNumberOfKeysReleasedForReading(), concurrencyManager
.getTotalNumberOfKeysReleasedForReadingBlewUpExceptionDueToCacheKeyHavingReachedCounterZero(),
concurrencyManager.getDepth()});
}
}
/**
* We have a thread that is not evolving for quite some while. This is a fairy good indication of eclipselink being
* stuck in a dead lock. So we log some information about the thread that is stuck.
*
* @param elapsedTime
* how many ms have passed since the thread stopped moving
* @param concurrencyManager
* the current cache key that the thread is trying to acquire or the object where the thread is waiting
* for the release deferred locks .
* @param lockManager
* the lock manager
* @param readLockManager
* the read lock manager
* @return Return the string with the tiny message we logged on the server log. This message can be interesting if
* we decide to fire up an interrupted exception
*/
protected String currentThreadIsStuckForSomeTimeProduceTinyLogMessage(long elapsedTime, ConcurrencyManager concurrencyManager, DeferredLockManager lockManager, ReadLockManager readLockManager) {
// We believe this is a dead lock so now we will log some information
Thread currentThread = Thread.currentThread();
String threadName = currentThread.getName();
String currentCacheKeyContext = createToStringExplainingOwnedCacheKey(concurrencyManager);
StringWriter errorMessage = new StringWriter();
long messageNumber = currentTinyMessageLogDumpNumber.incrementAndGet();
// (i) Create a big head to explain the cache key we were in when we blow up
errorMessage.write(TraceLocalization.buildMessage("concurrency_util_header_current_cache_key", new Object[] {threadName}));
// explain the cache key itself where the problem is taking place
errorMessage.write(TraceLocalization.buildMessage("concurrency_util_stuck_thread_tiny_log_cache_key", new Object[] { messageNumber, threadName, currentCacheKeyContext, elapsedTime }));
// (ii) Add information about the cache keys where the current thread was set as actively owning
errorMessage.write(createStringWithSummaryOfActiveLocksOnThread(lockManager, threadName));
// (iii) Now very interesting as well are all of the objects that current thread could not acquire the
// deferred locks are essential
errorMessage.write(createStringWithSummaryOfDeferredLocksOnThread(lockManager, threadName));
// (iv) Add information about all cache keys te current thread acquired with READ permission
errorMessage.write(createStringWithSummaryOfReadLocksAcquiredByThread(readLockManager, threadName));
AbstractSessionLog.getLog().log(SessionLog.SEVERE, SessionLog.CACHE, errorMessage.toString(), new Object[] {}, false);
threadLocalDateWhenCurrentThreadLastComplainedAboutBeingStuckInDeadLock.set(new Date());
return errorMessage.toString();
}
public boolean tooMuchTimeHasElapsed(final long whileStartTimeMillis, final long maxAllowedSleepTimeMs) {
if (maxAllowedSleepTimeMs == 0L) {
return false;
}
long elapsedTime = System.currentTimeMillis() - whileStartTimeMillis;
return elapsedTime > maxAllowedSleepTimeMs;
}
/**
* Invoke the {@link #dumpConcurrencyManagerInformationStep01(Map, Map, Map, Map, Map, Map, Map, Set, Map, Map)} if sufficient time has passed.
* This log message will potentially create a massive dump in the server log file. So we need to check when was the
* last time that the masive dump was produced and decide if we can log again the state of the concurrency manager.
*
* The access to dateWhenLastConcurrencyManagerStateFullDumpWasPerformedLock is synchronized, because we do not want
* two threads in parallel to star deciding to dump the complete state of the concurrency manager at the same time.
* Only one thread should succeed in producing the massive dump in a given time window.
*
*/
public void dumpConcurrencyManagerInformationIfAppropriate() {
// We do not want create a big synchronized method that would be dangerous
// but we want to make sure accessing the dateWhenLastConcurrencyManagerStateFullDumpWasPerformedLock is only
// done
// by cone thread at a time
synchronized (dateWhenLastConcurrencyManagerStateFullDumpWasPerformedLock) {
final long maxAllowedFrequencyToProduceMassiveDumpLogMessage = getMaxAllowedFrequencyToProduceMassiveDumpLogMessage();
boolean tooMuchTimeHasElapsedSinceLastLoggingOfMassiveMessage = tooMuchTimeHasElapsed(
dateWhenLastConcurrencyManagerStateFullDumpWasPerformed,
maxAllowedFrequencyToProduceMassiveDumpLogMessage);
if (!tooMuchTimeHasElapsedSinceLastLoggingOfMassiveMessage) {
// before we can fire to the serverlog such a gigantic message
// we need to allow for more time to pass (e.g. once a minute should be fine)
// it is not like production will be waiting for half an hour for a fozen system to magically
// start working if we do 30 dumps in a half an hour ... it is really irrelevant
return;
}
// we should proceed with making the big log dump - update the date of when the big dump was last done
dateWhenLastConcurrencyManagerStateFullDumpWasPerformed = System.currentTimeMillis();
}
// do the "MassiveDump" logging if enough time has passed since the previous massive dump logging
Map<Thread, DeferredLockManager> deferredLockManagers = ConcurrencyManager.getDeferredLockManagers();
Map<Thread, ReadLockManager> readLockManagersOriginal = ConcurrencyManager.getReadLockManagers();
Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireOriginal = ConcurrencyManager.getThreadsToWaitOnAcquire();
Map<Thread, String> mapThreadToWaitOnAcquireMethodNameOriginal = ConcurrencyManager.getThreadsToWaitOnAcquireMethodName();
Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireReadLockOriginal = ConcurrencyManager.getThreadsToWaitOnAcquireReadLock();
Map<Thread, String> mapThreadToWaitOnAcquireReadLockMethodNameOriginal = ConcurrencyManager.getThreadsToWaitOnAcquireReadLockMethodName();
Map<Thread, Set<ConcurrencyManager>> mapThreadToWaitOnAcquireInsideWriteLockManagerOriginal = WriteLockManager.getThreadToFailToAcquireCacheKeys();
Set<Thread> setThreadWaitingToReleaseDeferredLocksOriginal = ConcurrencyManager.getThreadsWaitingToReleaseDeferredLocks();
Map<Thread, String> mapThreadsThatAreCurrentlyWaitingToReleaseDeferredLocksJustificationClone = ConcurrencyManager.getThreadsWaitingToReleaseDeferredLocksJustification();
Map<Thread, Set<Object>> mapThreadToObjectIdWithWriteLockManagerChangesOriginal = WriteLockManager.getMapWriteLockManagerThreadToObjectIdsWithChangeSet();
dumpConcurrencyManagerInformationStep01(
deferredLockManagers,
readLockManagersOriginal,
mapThreadToWaitOnAcquireOriginal,
mapThreadToWaitOnAcquireMethodNameOriginal,
mapThreadToWaitOnAcquireInsideWriteLockManagerOriginal,
mapThreadToWaitOnAcquireReadLockOriginal,
mapThreadToWaitOnAcquireReadLockMethodNameOriginal,
setThreadWaitingToReleaseDeferredLocksOriginal,
mapThreadsThatAreCurrentlyWaitingToReleaseDeferredLocksJustificationClone,
mapThreadToObjectIdWithWriteLockManagerChangesOriginal);
}
/**
* The current working thread is having problems. It seems to not go forward being stuck either trying to acquire a
* cache key for writing, as a deferred cache key or it is at the end of the process and it is waiting for some
* other thread to finish building some objects it needed to defer.
*
* Now that the system is frozen we want to start spamming into the server log file the state of the concurrency
* manager since this might help us understand the situation of the system.
*
*
* @param deferredLockManagers
* static map coming from the concurrency manager telling us all the threds and their defferred locks and
* active locks
* @param readLockManagersOriginal
* static map coming from the concurrency manager telling us all the threads and their read locks
* @param mapThreadToWaitOnAcquireOriginal
* static map of threads that have registered themselves as waiting for some cache key
*
* @param mapThreadToWaitOnAcquireInsideWriteLockManagerOriginal
* this map relates to the fact that the write lock manager during transaction commits is very illusive.
* The write lock manger is not allowing itself to get stuck on acquiring any cache key. It uses waits
* with timings and therefore the locks needed to write and that cannot be obtained are not appearing
* inside our tracebility maps of the concurrency manager. We needed add the
* {@link org.eclipse.persistence.internal.helper.WriteLockManager#THREAD_TO_FAIL_TO_ACQUIRE_CACHE_KEYS}
* but semantically this map is 100 percent the same thing as the mapThreadToWaitOnAcquireOriginal. It
* still represents a thread wanting to grab a write lock and not managing to get it. Being stuck in that
* step. Wo we will want to fuse together the (mapThreadToWaitOnAcquireOriginal and the
* mapThreadToWaitOnAcquireInsideWriteLockManagerOriginal) to make our lives much easier.
*
*
* @param setThreadWaitingToReleaseDeferredLocksOriginal
* static map of threads that have stopped going deeped in the recursion of object building and are
* waiting for the confirmation that some of the objects they needed to build are finished building.
*
* @param mapThreadToObjectIdWithWriteLockManagerChangesOriginal
* The write lock manager has been tweaked to store information about objects ids that the current thread
* has in its hands and that will required for write locks to be acquired by a committing thread. This
* information is especially interesting if any thread participating in a dead lock is getting stuck in
* the acquisition of write locks as part of the commit process. This information might end up revealing
* a thread that has done too many changes and is creating a bigger risk fo dead lock. The more resources
* an individual thread tries to grab the worse it is for the concurrency layer. The size of the change
* set can be interesting.
*/
protected void dumpConcurrencyManagerInformationStep01(Map<Thread, DeferredLockManager> deferredLockManagers,
Map<Thread, ReadLockManager> readLockManagersOriginal,
Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireOriginal,
Map<Thread, String> mapThreadToWaitOnAcquireMethodNameOriginal,
Map<Thread, Set<ConcurrencyManager>> mapThreadToWaitOnAcquireInsideWriteLockManagerOriginal,
Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireReadLockOriginal,
Map<Thread, String> mapThreadToWaitOnAcquireReadLockMethodNameOriginal,
Set<Thread> setThreadWaitingToReleaseDeferredLocksOriginal,
Map<Thread, String> mapThreadsThatAreCurrentlyWaitingToReleaseDeferredLocksJustificationClone,
Map<Thread, Set<Object>> mapThreadToObjectIdWithWriteLockManagerChangesOriginal) {
// (a) create object to represent our cache state.
ConcurrencyManagerState concurrencyManagerState = createConcurrencyManagerState(
deferredLockManagers,
readLockManagersOriginal,
mapThreadToWaitOnAcquireOriginal,
mapThreadToWaitOnAcquireMethodNameOriginal,
mapThreadToWaitOnAcquireInsideWriteLockManagerOriginal,
mapThreadToWaitOnAcquireReadLockOriginal,
mapThreadToWaitOnAcquireReadLockMethodNameOriginal,
setThreadWaitingToReleaseDeferredLocksOriginal,
mapThreadsThatAreCurrentlyWaitingToReleaseDeferredLocksJustificationClone,
mapThreadToObjectIdWithWriteLockManagerChangesOriginal);
dumpConcurrencyManagerInformationStep02(concurrencyManagerState);
}
/**
* Dump the server log all of the information that we managed to aggregate about the current state of the
* concurrency manager.
*
* @param concurrencyManagerState a snapshot of the current state of the concurrency manager and threads accessing locks.
*/
protected void dumpConcurrencyManagerInformationStep02(ConcurrencyManagerState concurrencyManagerState) {
StringWriter writer = new StringWriter();
long messageNumber = currentMassiveDumpMessageLogDumpNumber.incrementAndGet();
writer.write(TraceLocalization.buildMessage("concurrency_util_dump_concurrency_manager_information_step02_01", new Object[] {messageNumber}));
// (a) Log information about the current threads in the system and there stack traces
// PAGE 01 of logging information
writer.write(createInformationThreadDump());
// (b) log information about the threads that are waiting to acquire WRITE/DEFERRED locks
// PAGE 02 of logging information
writer.write(createInformationAboutAllThreadsWaitingToAcquireReadCacheKeys(concurrencyManagerState.getMapThreadToWaitOnAcquireReadLockClone(),
concurrencyManagerState.getMapThreadToWaitOnAcquireReadLockCloneMethodName()));
// (c) log information about the threads that are waiting to acquire READ locks
// PAGE 03 of logging information
writer.write(createInformationAboutAllThreadsWaitingToAcquireReadCacheKeys(concurrencyManagerState.getMapThreadToWaitOnAcquireReadLockClone(),
concurrencyManagerState.getMapThreadToWaitOnAcquireReadLockCloneMethodName()));
// (c) An interesting summary of information as well is to tell the user about the threads
// that have finished their part of object building and now would like for othe threads to finish the object
// building of locks they had to defer
// PAGE 04 of logging information
writer.write(createInformationAboutAllThreadsWaitingToReleaseDeferredLocks(concurrencyManagerState.getSetThreadWaitingToReleaseDeferredLocksClone()));
// (d) Now we log information from the prespective of a THREAD to resources it has acquired and those
// it needed to defer
// PAGE 05 of logging information
writer.write(createInformationAboutAllResourcesAcquiredAndDeferredByAllThreads(concurrencyManagerState));
// (e) Dump information by going from cache key to the threads with some sort of relationship to the key
// PAGE 06 of logging information
writer.write(createInformationAboutCacheKeysAndThreadsMakingUseOfTheCacheKey(
concurrencyManagerState.getMapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey()));
// (f) Try to explain the reason for the dead lock:
// PAGE 07: we try to find out the reason for the dead lock
// but based on what we have seen so far it is mostly due to cache key corruption
// with the number of readers increased
String deadLockExplanation = dumpDeadLockExplanationIfPossible(concurrencyManagerState);
writer.write(deadLockExplanation);
// (g) Final header
writer.write(TraceLocalization.buildMessage("concurrency_util_dump_concurrency_manager_information_step02_02", new Object[] {messageNumber}));
// there should be no risk that the string is simply to big. the max string size in java is 2pow31 chars
// which means 2 GB string... we can be fairly confident we are not logging 2 GB in a single message.
// not even in the largest of sites...
AbstractSessionLog.getLog().log(SessionLog.SEVERE, SessionLog.CACHE, writer.toString(), new Object[] {}, false);
}
/**
* Log information focusing on the different cache keys where threads have hooks on the thread.
*
* @param mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey
* a map that we have constructed where the map keys are cache keys that are of some sort of interest to
* one or more threads (e.g. cache keys with a read lock, acquired or deferred)
*
*/
private String createInformationAboutCacheKeysAndThreadsMakingUseOfTheCacheKey(
Map<ConcurrencyManager, CacheKeyToThreadRelationships> mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey) {
// (a) Create a header string of information
StringWriter writer = new StringWriter();
int numberOfCacheKeysGettingDescribed = mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey.size();
writer.write(TraceLocalization.buildMessage("concurrency_util_cache_keys_threads_making_use_cache_key_01", new Object[] {numberOfCacheKeysGettingDescribed}));
int currentCacheKeyNumber = 0;
for(Map.Entry<ConcurrencyManager, CacheKeyToThreadRelationships> currentEntry : mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey.entrySet()) {
currentCacheKeyNumber++;
// (b) put a clear separator from the line above
writer.write(TraceLocalization.buildMessage("concurrency_util_cache_keys_threads_making_use_cache_key_02", new Object[] {currentCacheKeyNumber, numberOfCacheKeysGettingDescribed}));
// (c) Describe the current cache key
ConcurrencyManager cacheKey = currentEntry.getKey();
String cacheKeyToString = createToStringExplainingOwnedCacheKey(cacheKey);
CacheKeyToThreadRelationships dto = currentEntry.getValue();
writer.write(TraceLocalization.buildMessage("concurrency_util_cache_keys_threads_making_use_cache_key_03", new Object[] {currentCacheKeyNumber, cacheKeyToString,
dto.getThreadNamesThatAcquiredActiveLock(), dto.getThreadNamesThatAcquiredDeferredLock(), dto.getThreadNamesThatAcquiredReadLock(),
dto.getThreadNamesKnownToBeStuckTryingToAcquireLock(), dto.getThreadNamesKnownToBeStuckTryingToAcquireLockForReading()}));
}
writer.write(TraceLocalization.buildMessage("concurrency_util_cache_keys_threads_making_use_cache_key_04"));
return writer.toString();
}
protected String dumpDeadLockExplanationIfPossible(ConcurrencyManagerState concurrencyManagerState) {
// (a) Step one - try to detect dead lock
final long startTimeMillis = System.currentTimeMillis();
List<DeadLockComponent> deadLockExplanation = Collections.emptyList();
long deadLockDetectionTotalExecutionTimeMs = 0l;
try {
deadLockExplanation = ExplainDeadLockUtil.SINGLETON.explainPossibleDeadLockStartRecursion(concurrencyManagerState);
} catch (Exception codeIsBuggyAndBlowingUp) {
// we are unsure if the code will actually work and help
// therefore we make sure we catch any blowup coming from here
AbstractSessionLog.getLog().logThrowable(SessionLog.SEVERE, SessionLog.CACHE, new Exception(
TraceLocalization.buildMessage("concurrency_util_dump__dead_lock_explanation_01"),
codeIsBuggyAndBlowingUp));
} finally {
final long endTimeMillis = System.currentTimeMillis();
deadLockDetectionTotalExecutionTimeMs = endTimeMillis - startTimeMillis;
}
// (b) explain what has happened
StringWriter writer = new StringWriter();
writer.write(TraceLocalization.buildMessage("concurrency_util_dump__dead_lock_explanation_02"));
if (deadLockExplanation.isEmpty()) {
writer.write(TraceLocalization.buildMessage("concurrency_util_dump__dead_lock_explanation_03"));
} else {
// (i) Write out a summary of how many threads are involved in the deadloc
writer.write(TraceLocalization.buildMessage("concurrency_util_dump__dead_lock_explanation_04", new Object[] {deadLockExplanation.size()}));
// (ii) Print them all out
for (int currentThreadNumber = 0; currentThreadNumber < deadLockExplanation.size(); currentThreadNumber++) {
writer.write(TraceLocalization.buildMessage("concurrency_util_dump__dead_lock_explanation_05", new Object[] {currentThreadNumber + 1, deadLockExplanation.get(currentThreadNumber).toString()}));
}
}
// (c) return the string that tries to explain the reason for the dead lock
writer.write(TraceLocalization.buildMessage("concurrency_util_dump__dead_lock_explanation_06", new Object[] {deadLockDetectionTotalExecutionTimeMs}));
return writer.toString();
}
/**
* create a DTO that tries to represent the current snapshot of the concurrency manager and write lock manager cache
* state
*/
public ConcurrencyManagerState createConcurrencyManagerState(
Map<Thread, DeferredLockManager> deferredLockManagers,
Map<Thread, ReadLockManager> readLockManagersOriginal,
Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireOriginal,
Map<Thread, String> mapThreadToWaitOnAcquireMethodNameOriginal,
Map<Thread, Set<ConcurrencyManager>> mapThreadToWaitOnAcquireInsideWriteLockManagerOriginal,
Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireReadLockOriginal,
Map<Thread, String> mapThreadToWaitOnAcquireReadLockMethodNameOriginal,
Set<Thread> setThreadWaitingToReleaseDeferredLocksOriginal,
Map<Thread, String> mapThreadsThatAreCurrentlyWaitingToReleaseDeferredLocksJustificationClone,
Map<Thread, Set<Object>> mapThreadToObjectIdWithWriteLockManagerChangesOriginal) {
// (a) As a first step we want to clone-copy the two maps
// once we start working with the maps and using them to do dead lock detection
// or simply print the state of the system we do not want the maps to continue changing as the threads referenced in the maps
// go forward with their work
Map<Thread, ReadLockManager> readLockManagerMapClone = cloneReadLockManagerMap(readLockManagersOriginal);
Map<Thread, DeferredLockManager> deferredLockManagerMapClone = cloneDeferredLockManagerMap(deferredLockManagers);
// NOTE: the wait on acquire write locks are tricky
// we want to fuse together the threads we are tracking waiting to acquire locks
// both the one we track in the hash map of the concurrency manager
// as well as the ones we need to track inside of the write lock manager
Map<Thread, Set<ConcurrencyManager>> unifiedMapOfThreadsStuckTryingToAcquireWriteLock = null;
// additional method data about the method that created the trace
Map<Thread, String> mapThreadToWaitOnAcquireMethodNameClone = cloneMapThreadToMethodName(mapThreadToWaitOnAcquireMethodNameOriginal);
{
// information from the concurrency manager state
Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireClone = cloneMapThreadToWaitOnAcquire(mapThreadToWaitOnAcquireOriginal);
// info from the the write lock manager state
Map<Thread, Set<ConcurrencyManager>> mapThreadToWaitOnAcquireInsideWriteLockManagerClone = cloneMapThreadToWaitOnAcquireInsideWriteLockManagerOriginal(
mapThreadToWaitOnAcquireInsideWriteLockManagerOriginal);
// merge both maps together
enrichMapThreadToWaitOnAcquireInsideWriteLockManagerClone(mapThreadToWaitOnAcquireInsideWriteLockManagerClone, mapThreadToWaitOnAcquireClone);
// update the variable we want to be carrying forward to be the enriched map
unifiedMapOfThreadsStuckTryingToAcquireWriteLock = mapThreadToWaitOnAcquireInsideWriteLockManagerClone;
}
Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireReadLockClone = cloneMapThreadToWaitOnAcquire(mapThreadToWaitOnAcquireReadLockOriginal);
Map<Thread, String> mapThreadToWaitOnAcquireReadLockMethodNameClone = cloneMapThreadToMethodName(mapThreadToWaitOnAcquireReadLockMethodNameOriginal);
Set<Thread> setThreadWaitingToReleaseDeferredLocksClone = cloneSetThreadsThatAreCurrentlyWaitingToReleaseDeferredLocks(setThreadWaitingToReleaseDeferredLocksOriginal);
Map<Thread, Set<Object>> mapThreadToObjectIdWithWriteLockManagerChangesClone = cloneMapThreadToObjectIdWithWriteLockManagerChanges(
mapThreadToObjectIdWithWriteLockManagerChangesOriginal);
// (b) All of the above maps tell a story from the respective of the threads
// very interesting as well is to be able to go over the story of the cache keys and what threads have
// expectations for these cache keys
Map<ConcurrencyManager, CacheKeyToThreadRelationships> mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey = new HashMap<>();
// (i) pump information about the read locks
enrichMapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKeyInfoAboutReadLocks(
mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey, readLockManagerMapClone);
// (ii) pump information about the active and deferred locks
enrichMapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKeyInfoAboutActiveAndDeferredLocks(
mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey, deferredLockManagerMapClone);
// (iii) Pump information into the map about the threads that are stuck because they cannot acquire a certain
// cache key (they want to acquire the cache key for WRITING either to become active thread or to defer)
enrichMapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKeyInfoThreadsStuckOnAcquire(
mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey, unifiedMapOfThreadsStuckTryingToAcquireWriteLock);
// (iv) Pump information into the map about the threads that are stuck because they cannot acquire a certain
// cache key (they want to acquire the cache key for READING)
enrichMapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKeyInfoThreadsStuckOnAcquireLockForReading(
mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey, mapThreadToWaitOnAcquireReadLockClone);
return new ConcurrencyManagerState(
readLockManagerMapClone, deferredLockManagerMapClone, unifiedMapOfThreadsStuckTryingToAcquireWriteLock,
mapThreadToWaitOnAcquireMethodNameClone, mapThreadToWaitOnAcquireReadLockClone, mapThreadToWaitOnAcquireReadLockMethodNameClone,
setThreadWaitingToReleaseDeferredLocksClone, mapThreadsThatAreCurrentlyWaitingToReleaseDeferredLocksJustificationClone,
mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey, mapThreadToObjectIdWithWriteLockManagerChangesClone);
}
/**
* Create a print of the ACTIVE locks associated to the DeferredLockManager. Owning an active lock on a thread
* implies that the thread is allowed to do write operations in relation to the object.
*/
private String createStringWithSummaryOfActiveLocksOnThread(DeferredLockManager lockManager, String threadName) {
// (a) Make sure the lock manager being passed is not null
StringWriter writer = new StringWriter();
writer.write(TraceLocalization.buildMessage("concurrency_util_header_active_locks_owned_by_thread", new Object[] {threadName}));
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_active_locks_on_thread_1", new Object[] {threadName}));
if (lockManager == null) {
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_active_locks_on_thread_2"));
return writer.toString();
}
// (b) Try to build a string that lists all of the active locks on the thread
// Loop over all of the active locks and print them
List<ConcurrencyManager> activeLocks = new ArrayList<>(lockManager.getActiveLocks());
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_active_locks_on_thread_3", new Object[] {activeLocks.size()}));
for (int activeLockNumber = 0; activeLockNumber < activeLocks.size(); activeLockNumber++) {
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_active_locks_on_thread_4", new Object[] {activeLockNumber, createToStringExplainingOwnedCacheKey(activeLocks.get(activeLockNumber))}));
}
return writer.toString();
}
/**
* The {@link org.eclipse.persistence.internal.helper.DeferredLockManager} contains two baskat of locks being
* managed for a thread. One are active locks (granted write permission). The other deferred locks (write access or
* read access was being held by somebody else and the thread deferred).
*
* @param lockManager
* the deferred lock manager of the current thread
* @return
*/
private String createStringWithSummaryOfDeferredLocksOnThread(DeferredLockManager lockManager, String threadName) {
// (a) Make sure the lock manager being passed is not null
StringWriter writer = new StringWriter();
writer.write(TraceLocalization.buildMessage("concurrency_util_header_deferred_locks_owned_by_thread", new Object[] {threadName}));
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_deferred_locks_on_thread_1", new Object[] {threadName}));
if (lockManager == null) {
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_deferred_locks_on_thread_2"));
return writer.toString();
}
// (b) Try to build a string that lists all of the active locks on the thread
// Loop over all of the deferred locks and print them
@SuppressWarnings("unchecked")
List<ConcurrencyManager> deferredLocks = new ArrayList<>(lockManager.getDeferredLocks());
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_deferred_locks_on_thread_3", new Object[] {deferredLocks.size()}));
for (int deferredLockNumber = 0; deferredLockNumber < deferredLocks.size(); deferredLockNumber++) {
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_deferred_locks_on_thread_4", new Object[] {deferredLockNumber, createToStringExplainingOwnedCacheKey(deferredLocks.get(deferredLockNumber))}));
}
return writer.toString();
}
/**
* Relates to issue. We are convinced that a read lock manager is needed for two reasons: implementing a
* dead lock detection algorithm which are currently not doing. And also beause when the code does not go according
* to happy path and do encounter a dead lock and forced to interrupt the thread, we need to force the thread to
* release any acquired a read locks it may have.
*
* @param readLockManager
* this is hacky class we created to close a gap in eclipselink code whereby read access on cache keys is
* not tracked. The only thing that happens is incrementing the nuber of readers but that is not
* sufficient if we need to abort all read locks.
* @param threadName
* the thread for which we are logging the read locks acquired
* @return A big string summarizing all of the read locks the thread.
*/
private String createStringWithSummaryOfReadLocksAcquiredByThread(ReadLockManager readLockManager, String threadName) {
// (a) Make sure the lock manager being passed is not null
StringWriter writer = new StringWriter();
writer.write(TraceLocalization.buildMessage("concurrency_util_header_reader_locks_owned_by_thread", new Object[] {threadName}));
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_read_locks_on_thread_step001_1", new Object[] {threadName}));
if (readLockManager == null) {
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_read_locks_on_thread_step001_2"));
return writer.toString();
}
// (b) Try to build a string that lists all of the acitve locks on the thread
// Loop over al of the active locks and print them
@SuppressWarnings("unchecked")
List<ConcurrencyManager> readLocks = readLockManager.getReadLocks();
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_read_locks_on_thread_step001_3", new Object[] {readLocks.size()}));
for (int readLockNumber = 0; readLockNumber < readLocks.size(); readLockNumber++) {
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_read_locks_on_thread_step001_4", new Object[] {readLockNumber + 1, createToStringExplainingOwnedCacheKey(readLocks.get(readLockNumber))}));
}
// (c) This is the main point of candidate 007 - having a lot fatter information about when and where the read
// locks were acquired
// (i) If a thread has 48 read locks most likely it acquired all 48 read locks in the exact same code area
// so we want to avoid dumping 48 stack traces to the massive dump that would be completely out of control
// we create a map of strings in order to know if we can refer to any previously created stack trace
Map<String, Long> stackTraceStringToStackTraceExampleNumber = new HashMap<>();
// (ii) Let us start dumping a mini header to give indication we now will sow very fact information about the
// read locks acquired by a thread
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_read_locks_on_thread_step002_1"));
// (iii) let us organize the iformation we are about to dump by the creation date of the records in the map
Map<Long, List<ReadLockAcquisitionMetadata>> mapThreadToReadLockAcquisitionMetadata = readLockManager.getMapThreadToReadLockAcquisitionMetadata();
List<Long> sortedThreadIds = new ArrayList<>(mapThreadToReadLockAcquisitionMetadata.keySet());
Collections.sort(sortedThreadIds);
// (iv) commence the loop of dumping trace data LOOP OVER EACH JPA TRANSACTION ID
for (Long currentThreadId : sortedThreadIds) {
List<ReadLockAcquisitionMetadata> readLocksAcquiredByThread = mapThreadToReadLockAcquisitionMetadata.get(currentThreadId);
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_read_locks_on_thread_step002_2", new Object[] {threadName, currentThreadId, readLocksAcquiredByThread.size()}));
// LOOP OVER EACH CACHE KEY ACQUIRED FORE READING BUT NEVER RELEASED FOR CURRENT THREAD ID
int readLockNumber = 0;
for (ReadLockAcquisitionMetadata currentReadLockAcquiredAndNeverReleased : readLocksAcquiredByThread) {
readLockNumber++;
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_read_locks_on_thread_step002_3", new Object[] {readLockNumber,
SINGLETON.createToStringExplainingOwnedCacheKey(currentReadLockAcquiredAndNeverReleased.getCacheKeyWhoseNumberOfReadersThreadIsIncrementing()),
ConversionManager.getDefaultManager().convertObject(currentReadLockAcquiredAndNeverReleased.getDateOfReadLockAcquisition(), String.class).toString(),
currentReadLockAcquiredAndNeverReleased.getNumberOfReadersOnCacheKeyBeforeIncrementingByOne(),
currentReadLockAcquiredAndNeverReleased.getCurrentThreadStackTraceInformationCpuTimeCostMs()}));
String stackTraceInformation = currentReadLockAcquiredAndNeverReleased.getCurrentThreadStackTraceInformation();
if (stackTraceStringToStackTraceExampleNumber.containsKey(stackTraceInformation)) {
// we can spare the massive dump from being any fatter we have alreayd added a stack trace id that
// is identical to the stack trace were were about dump
// we just refer to the stack trace id.
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_read_locks_on_thread_step002_4", new Object[] {readLockNumber, stackTraceStringToStackTraceExampleNumber.get(stackTraceInformation)}));
} else {
// Since we have not see this stack trace pattern for this thread yet we will dump the stack trace
// into the massive dump giving it a new global id
long stackTraceId = stackTraceIdAtomicLong.incrementAndGet();
stackTraceStringToStackTraceExampleNumber.put(stackTraceInformation, stackTraceId);
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_read_locks_on_thread_step002_5", new Object[] {readLockNumber, stackTraceId, stackTraceInformation}));
}
writer.write("\n\n");
}
}
// (d) We have some more information to pump out namely errors we have traced each time the number of readers was decremented
writer.write("\n\n");
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_read_locks_on_thread_step002_6", new Object[] {threadName, readLockManager.getRemoveReadLockProblemsDetected().size()}));
for (int releaseReadLockProblemNumber = 0; releaseReadLockProblemNumber < readLockManager.getRemoveReadLockProblemsDetected().size(); releaseReadLockProblemNumber++) {
writer.write(TraceLocalization.buildMessage("concurrency_util_summary_read_locks_on_thread_step002_7", new Object[] {releaseReadLockProblemNumber + 1, readLockManager.getRemoveReadLockProblemsDetected().get(releaseReadLockProblemNumber)}));
}
writer.write("\n\n");
return writer.toString();
}
/**
* This helper API is created due to the problem of the corruption of the eclipselink cache. The idea is to have a
* tool that allows us to know specifically where the current thread was located when it acquired a READ LOCK.
*
* <P>
* Cache corruption problem: <br>
* namely the fact that when dead locks are seen to be taking place some of the threads that seem to be primary
* culprits of the dead lock are actually idle doing nothing but they have have left the number of readers of the
* cache corrupted (e.g. typically forever incremnted).
*
* @return get the stack trace of the current thread.
*/
public String enrichGenerateThreadDumpForCurrentThread() {
final Thread currentThread = Thread.currentThread();
final long currentThreadId = currentThread.getId();
try {
// (a) search for the stack trace of the current
final StringWriter writer = new StringWriter();
ThreadInfo[] threadInfos = null;
if (PrivilegedAccessHelper.shouldUsePrivilegedAccess()) {
threadInfos = AccessController.doPrivileged(new PrivilegedGetThreadInfo(new long[] { currentThreadId }, 700));
} else {
final ThreadMXBean threadMXBean = ManagementFactory.getThreadMXBean();
threadInfos = threadMXBean.getThreadInfo(new long[] { currentThreadId }, 700);
}
for (ThreadInfo threadInfo : threadInfos) {
enrichGenerateThreadDumpForThreadInfo(writer, threadInfo);
}
return writer.toString();
} catch (Exception failToAcquireThreadDumpProgrammatically) {
AbstractSessionLog.getLog().logThrowable(SessionLog.SEVERE, SessionLog.CACHE, failToAcquireThreadDumpProgrammatically);
return TraceLocalization.buildMessage("concurrency_util_enrich_thread_dump", new Object[] {failToAcquireThreadDumpProgrammatically.getMessage()});
}
}
/**
* We simply copy pasted this code from the net to have some helper tool to generate thread dumps programatically
* when the event takes place.
*
* <P>
* NOTE: This approach can be easily tested in a basic unit test.
*
*
* <a href="https://crunchify.com/how-to-generate-java-thread-dump-programmatically/">Original source of code</a>
*
*/
private String enrichGenerateThreadDump() {
try {
final StringWriter writer = new StringWriter();
ThreadInfo[] threadInfos = null;
if (PrivilegedAccessHelper.shouldUsePrivilegedAccess()) {
threadInfos = AccessController.doPrivileged(new PrivilegedGetThreadInfo(700));
} else {
final ThreadMXBean threadMXBean = ManagementFactory.getThreadMXBean();
threadInfos = threadMXBean.getThreadInfo(threadMXBean.getAllThreadIds(), 700);
}
for (ThreadInfo threadInfo : threadInfos) {
enrichGenerateThreadDumpForThreadInfo(writer, threadInfo);
}
return writer.toString();
} catch (Exception failToAcquireThreadDumpProgrammatically) {
AbstractSessionLog.getLog().logThrowable(SessionLog.SEVERE, SessionLog.CACHE, failToAcquireThreadDumpProgrammatically);
return TraceLocalization.buildMessage("concurrency_util_enrich_thread_dump", new Object[] {failToAcquireThreadDumpProgrammatically.getMessage()});
}
}
/**
* Enrich a given string building with the the thread writer for a given thread info object.
*/
private void enrichGenerateThreadDumpForThreadInfo(StringWriter writer, ThreadInfo threadInfo) {
writer.write(TraceLocalization.buildMessage("concurrency_util_enrich_thread_dump_thread_info_1", new Object[] {threadInfo.getThreadName(), threadInfo.getThreadState()}));
final StackTraceElement[] stackTraceElements = threadInfo.getStackTrace();
for (final StackTraceElement stackTraceElement : stackTraceElements) {
writer.write(TraceLocalization.buildMessage("concurrency_util_enrich_thread_dump_thread_info_2", new Object[] {stackTraceElement}));
}
writer.write("\n\n");
}
/**
* Write a severe log message with the current thread dump.
*/
private String createInformationThreadDump() {
StringWriter writer = new StringWriter();
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_thread_dump", new Object[] {enrichGenerateThreadDump()}));
return writer.toString();
}
/**
* In this page of log dumping information we want to give a summary to the user of threads that appear to be stuck
* doing an acquire of the cache key.
*
* @param unifiedMapOfThreadsStuckTryingToAcquireWriteLock
* this a cloned map that has an association between thread and cache keys the thread would like to
* acquire but cannot because there are readers on the cache key. The thread might be stuck either on the
* concurrency manager or on the write lock manager.
* @param mapThreadToWaitOnAcquireMethodNameClone
* the name of the method that updated the
* {@link org.eclipse.persistence.internal.helper.ConcurrencyManager#THREADS_TO_WAIT_ON_ACQUIRE} If we
* do not know the method name that created the trace then it must have been the
* {@link org.eclipse.persistence.internal.helper.WriteLockManager#addCacheKeyToMapWriteLockManagerToCacheKeysThatCouldNotBeAcquired(Thread, ConcurrencyManager, long)}
* . This is not obvious but essentially we trace the acquisition of write locks in to places. The first
* is the map already mentioned in the concurrency manager. The second is the map
* {@link org.eclipse.persistence.internal.helper.WriteLockManager#THREAD_TO_FAIL_TO_ACQUIRE_CACHE_KEYS}
* for the purose of the massive dump we act as if there was a single unified map. However when the
* MAP_THREAD_TO_WAIT_ON_ACQUIRE we not only add to this map the cache key we cannot acquire but also the
* method name. When we work with the map the THREADS_TO_FAIL_TO_ACQUIRE_CACHE_KEYS
* we just keep trace of the cache key that could not be acquired. This
* THREADS_TO_FAIL_TO_ACQUIRE_CACHE_KEYS is currently only used in one spot so we
* can avoid the trouble of adding even more tracing for this.
*/
private String createInformationAboutAllThreadsWaitingToAcquireCacheKeys(Map<Thread, Set<ConcurrencyManager>> unifiedMapOfThreadsStuckTryingToAcquireWriteLock,
Map<Thread, String> mapThreadToWaitOnAcquireMethodNameClone) {
// (a) Create a header string of information
StringWriter writer = new StringWriter();
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_acquire_cache_keys_1", new Object[] {unifiedMapOfThreadsStuckTryingToAcquireWriteLock.size()}));