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 1001 1002 1003 1004 1005 1006 1007 1008 1009 1010 1011 1012 1013 1014 1015 1016 1017 1018 1019 1020 1021 1022 1023 1024 1025 1026 1027 1028 1029 1030 1031 1032 1033 1034 1035 1036 1037 1038 1039 1040 1041 1042 1043 1044 1045 1046 1047 1048 1049 1050 1051 1052 1053 1054 1055 1056 1057 1058 1059 1060 1061 1062 1063 1064 1065 1066 1067 1068 1069 1070 1071 1072 1073 1074 1075 1076 1077 1078 1079 1080 1081 1082 1083 1084 1085 1086 1087 1088 1089 1090 1091 1092 1093 1094 1095 1096 1097 1098 1099 1100 1101 1102 1103 1104 1105 1106 1107 1108 1109 1110 1111 1112 1113 1114 1115 1116 1117 1118 1119 1120 1121 1122 1123 1124 1125 1126 1127 1128 1129 1130 1131 1132 1133 1134 1135 1136 1137 1138 1139 1140 1141 1142 1143 1144 1145 1146 1147 1148 1149 1150 1151 1152 1153 1154 1155 1156 1157 1158 1159 1160 1161 1162 1163 1164 1165 1166 1167 1168 1169 1170 1171 1172 1173 1174 1175 1176 1177 1178 1179 1180 1181 1182 1183 1184 1185 1186 1187 1188 1189 1190 1191 1192 1193 1194 1195 1196 1197 1198 1199 1200 1201 1202 1203 1204 1205 1206 1207 1208 1209 1210 1211 1212 1213 1214 1215 1216 1217 1218 1219 1220 1221 1222 1223 1224 1225 1226 1227 1228 1229 1230 1231 1232 1233 1234 1235 1236 1237 1238 1239 1240 1241 1242 1243 1244 1245 1246 1247 1248 1249 1250 1251 1252 1253 1254 1255 1256 1257 1258 1259 1260 1261 1262 1263 1264 1265 1266 1267 1268 1269 1270 1271 1272 1273 1274 1275 1276 1277 1278 1279 1280 1281 1282 1283 1284 1285 1286 1287 1288 1289 1290 1291 1292 1293 1294 1295 1296 1297 1298 1299 1300 1301 1302 1303 1304 1305 1306 1307 1308 1309 1310 1311 1312 1313 1314 1315 1316 1317 1318 1319 1320 1321 1322 1323 1324 1325 1326 1327 1328 1329 1330 1331 1332 1333 1334 1335 1336 1337 1338 1339 1340 1341 1342 1343 1344 1345 1346 1347 1348 1349 1350 1351 1352 1353 1354 1355 1356 1357 1358 1359 1360 1361 1362 1363 1364 1365 1366 1367 1368 1369 1370 1371 1372 1373 1374 1375 1376 1377 1378 1379 1380 1381 1382 1383 1384 1385 1386 1387 1388 1389 1390 1391 1392 1393 1394 1395 1396 1397 1398 1399 1400 1401 1402 1403 1404 1405 1406 1407 1408 1409 1410 1411 1412 1413 1414 1415 1416 1417 1418 1419 1420 1421 1422 1423 1424 1425 1426 1427 1428 1429 1430 1431 1432 1433 1434 1435 1436 1437 1438 1439 1440 1441 1442 1443 1444 1445 1446 1447 1448 1449 1450 1451 1452 1453 1454 1455 1456 1457 1458 1459 1460 1461 1462 1463 1464 1465 1466 1467 1468 1469 1470 1471 1472 1473 1474 1475 1476 1477 1478 1479 1480 1481 1482 1483 1484 1485 1486 1487 1488 1489 1490 1491 1492 1493 1494 1495 1496 1497 1498 1499 1500 1501 1502 1503 1504 1505 1506 1507 1508 1509 1510 1511 1512 1513 1514 1515 1516 1517 1518 1519 1520 1521 1522 1523 1524 1525 1526 1527 1528 1529 1530 1531 1532 1533 1534 1535 1536 1537 1538 1539 1540 1541 1542 1543 1544 1545 1546 1547 1548 1549 1550 1551 1552 1553 1554 1555 1556 1557 1558 1559 1560 1561 1562 1563 1564 1565 1566 1567 1568 1569 1570 1571 1572 1573 1574 1575 1576 1577 1578 1579 1580 1581 1582 1583 1584 1585 1586 1587 1588 1589 1590 1591 1592 1593 1594 1595 1596 1597 1598 1599 1600 1601 1602 1603 1604 1605 1606 1607 1608 1609 1610 1611 1612 1613 1614 1615 1616 1617 1618 1619 1620 1621 1622 1623 1624 1625 1626 1627 1628 1629 1630 1631 1632 1633 1634 1635 1636 1637 1638 1639 1640 1641 1642 1643 1644 1645 1646 1647 1648 1649 1650 1651 1652 1653 1654 1655 1656 1657 1658 1659 1660 1661 1662 1663 1664 1665 1666 1667 1668 1669 1670 1671 1672 1673 1674 1675 1676 1677 1678 1679 1680 1681 1682 1683 1684 1685 1686 1687 1688 1689 1690 1691 1692
|
/*
* 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()}));
int currentThreadNumber = 0;
for (Map.Entry<Thread, Set<ConcurrencyManager>> currentEntry : unifiedMapOfThreadsStuckTryingToAcquireWriteLock
.entrySet()) {
currentThreadNumber++;
Thread thread = currentEntry.getKey();
Set<ConcurrencyManager> writeLocksCurrentThreadIsTryingToAcquire = currentEntry.getValue();
for (ConcurrencyManager cacheKey : writeLocksCurrentThreadIsTryingToAcquire) {
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_acquire_cache_keys_2", new Object[] {currentThreadNumber, thread.getName(), createToStringExplainingOwnedCacheKey(cacheKey)}));
// add as well information about what method created this trace entry
// this important in case we start leaking traces when the code is configured
// to blow up
String methodNameThatGotStuckWaitingToAcquire = mapThreadToWaitOnAcquireMethodNameClone.get(currentEntry.getKey());
if (methodNameThatGotStuckWaitingToAcquire == null) {
// this because the acquire trace was not on the
// org.eclipse.persistence.internal.helper.ConcurrencyManager.MAP_THREAD_TO_WAIT_ON_ACQUIRE
// by the concurrency manager but rather the trace of the wait on the write
// lock was created by the mapThreadToWaitOnAcquireInsideWriteLockManagerClone
// see
// org.eclipse.persistence.internal.helper.WriteLockManager.addCacheKeyToMapWriteLockManagerToCacheKeysThatCouldNotBeAcquired(Thread, ConcurrencyManager, Date)
methodNameThatGotStuckWaitingToAcquire = TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_acquire_cache_keys_3");
}
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_acquire_cache_keys_4", new Object[] {methodNameThatGotStuckWaitingToAcquire}));
}
}
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_acquire_cache_keys_5"));
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 mapThreadToWaitOnAcquireReadLockClone
* this a cloned map that has an association between thread and cache keys the thread would like to
* acquire for READING but cannot because there is some active thread (other than themselves) holding the cache key (e.g. for writing)
*/
protected String createInformationAboutAllThreadsWaitingToAcquireReadCacheKeys(Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireReadLockClone,
Map<Thread, String> mapThreadToWaitOnAcquireReadLockMethodNameClone) {
// (a) Create a header string of information
StringWriter writer = new StringWriter();
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_acquire_read_cache_keys_1", new Object[] {mapThreadToWaitOnAcquireReadLockClone.size()}));
int currentThreadNumber = 0;
for(Map.Entry<Thread, ConcurrencyManager> currentEntry : mapThreadToWaitOnAcquireReadLockClone.entrySet()) {
currentThreadNumber++;
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_acquire_read_cache_keys_2", new Object[] {currentThreadNumber, currentEntry.getKey().getName(), createToStringExplainingOwnedCacheKey(currentEntry.getValue())}));
String methodNameThatGotStuckWaitingToAcquire = mapThreadToWaitOnAcquireReadLockMethodNameClone.get(currentEntry.getKey());
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_acquire_read_cache_keys_3", new Object[] {methodNameThatGotStuckWaitingToAcquire}));
}
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_acquire_read_cache_keys_4"));
return writer.toString();
}
/**
* Log information about threads not moving forward because they are waiting for the
* {@code isBuildObjectOnThreadComplete } to return true.
*
* @param setThreadWaitingToReleaseDeferredLocksClone
* threads waiting for the release deferred lock process to complete.
*/
protected String createInformationAboutAllThreadsWaitingToReleaseDeferredLocks(Set<Thread> setThreadWaitingToReleaseDeferredLocksClone) {
// (a) Create a header string of information
StringWriter writer = new StringWriter();
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_release_deferred_locks_1", new Object[] {setThreadWaitingToReleaseDeferredLocksClone.size()}));
// (b) add to the string building information about each of these threads that are stuck in the
// isBuildObjectOnThreadComplete
int currentThreadNumber = 0;
for (Thread currentEntry : setThreadWaitingToReleaseDeferredLocksClone) {
currentThreadNumber++;
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_release_deferred_locks_2", new Object[] {currentThreadNumber, currentEntry.getName()}));
}
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_threads_release_deferred_locks_3"));
return writer.toString();
}
/**
* Log information about all threads tracked in the concurrency manager.
*
* @param concurrencyManagerState
* and object that represents a snapshot of the current state of the concurrency manager.
*/
protected String createInformationAboutAllResourcesAcquiredAndDeferredByAllThreads(
ConcurrencyManagerState concurrencyManagerState) {
// (a) Compile a union of all threads
Set<Thread> allRelevantThreads = new HashSet<>();
allRelevantThreads.addAll(concurrencyManagerState.getSetThreadWaitingToReleaseDeferredLocksClone());
allRelevantThreads.addAll(concurrencyManagerState.getUnifiedMapOfThreadsStuckTryingToAcquireWriteLock().keySet());
allRelevantThreads.addAll(concurrencyManagerState.getDeferredLockManagerMapClone().keySet());
allRelevantThreads.addAll(concurrencyManagerState.getReadLockManagerMapClone().keySet());
// (b) print information about all threads
StringWriter writer = new StringWriter();
int currentThreadNumber = 0;
final int totalNumberOfThreads = allRelevantThreads.size();
for(Thread currentThread : allRelevantThreads) {
currentThreadNumber++;
ReadLockManager readLockManager = concurrencyManagerState.getReadLockManagerMapClone().get(currentThread);
DeferredLockManager lockManager = concurrencyManagerState.getDeferredLockManagerMapClone().get(currentThread);
String waitingToReleaseDeferredLocksJustification = concurrencyManagerState.getMapThreadsThatAreCurrentlyWaitingToReleaseDeferredLocksJustificationClone().get(currentThread);
Set<ConcurrencyManager> waitingOnAcquireCacheKeys = concurrencyManagerState
.getUnifiedMapOfThreadsStuckTryingToAcquireWriteLock()
.get(currentThread);
ConcurrencyManager waitingOnAcquireReadCacheKey = concurrencyManagerState
.getMapThreadToWaitOnAcquireReadLockClone().get(currentThread);
boolean threadWaitingToReleaseDeferredLocks = concurrencyManagerState
.getSetThreadWaitingToReleaseDeferredLocksClone().contains(currentThread);
Set<Object> writeManagerThreadPrimaryKeysWithChangesToBeMerged = concurrencyManagerState
.getMapThreadToObjectIdWithWriteLockManagerChangesClone()
.get(currentThread);
String informationAboutCurrentThread = createInformationAboutAllResourcesAcquiredAndDeferredByThread(
readLockManager, lockManager, waitingOnAcquireCacheKeys, waitingOnAcquireReadCacheKey,
threadWaitingToReleaseDeferredLocks, currentThread, currentThreadNumber, totalNumberOfThreads,
writeManagerThreadPrimaryKeysWithChangesToBeMerged, waitingToReleaseDeferredLocksJustification);
writer.write(informationAboutCurrentThread);
}
// (c) Log on the serverlog information about all the threads being tracked in the concurrency manager
return writer.toString();
}
/**
* Build a string that tries to describe in as much detail as possible the resources associated to the current
* thread.
*
* @param readLockManager
* the read lock manager for the current thread
* @param lockManager
* the lock manager for the current thread
* @param waitingOnAcquireCacheKeys
* null if the current thread is not waiting to acquire a cache key otherwise the cachekey that the
* current thread wants to acquire and that is making it block. This field evolved to be a set and not
* just one cache key because when we needed to tweak the write lock manager code to report about why the
* write lock manager is stuck we need it to create the map
* {@link org.eclipse.persistence.internal.helper.WriteLockManager#THREAD_TO_FAIL_TO_ACQUIRE_CACHE_KEYS}
* whereby during a commit where entiteis are merged into the shared cache a thread might be trying to
* grab several write locks. so here we have a mix between the concurrency manager cache key a thread
* currently wants together with cache keys the write lock managed is not managing to grab.
*
* @param waitingOnAcquireReadCacheKey
* cache key the thread is failing to acquire in the
* {@link org.eclipse.persistence.internal.helper.ConcurrencyManager#acquireReadLock()}
* @param threadWaitingToReleaseDeferredLocks
* true if the curren thread is now blocked waiting to confirm the locks it deferred have finished
* building the corresponding objects.
* @param thread
* the thread eing described
* @param currentThreadNumber
* just loop incremented index to help the dump log messages give the feeling of the current thread being
* described and how many more threads are still to be described
* @param totalNumberOfThreads
* the total number of threads being described in a for loop
* @return a string describing the thread provided. We can see the active locks, deferred locks, read locks etc...
* as well sa if the thread is waiting to acquire a specific cache key or waiting for build object to
* complete.
* @param writeManagerThreadPrimaryKeysWithChangesToBeMerged
* Null for all threads excep those that are currently about to commit and merge changes to the shared
* cache. In this case it holds the primary keys of the objects that were changed by the transaction. 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.
* @param waitingToReleaseDeferredLocksJustification
* when a thread is stuck for more than 500 ms in the release defferred locks algorithm, the concurrency
* manager starts try to justify why the method isBuildObjectComplete keeps returning false. This
* information is important whenever the param thread waiting to release deferred locks is true
*/
protected String createInformationAboutAllResourcesAcquiredAndDeferredByThread(
ReadLockManager readLockManager, DeferredLockManager lockManager,
Set<ConcurrencyManager> waitingOnAcquireCacheKeys, ConcurrencyManager waitingOnAcquireReadCacheKey,
boolean threadWaitingToReleaseDeferredLocks, Thread thread,
int currentThreadNumber, int totalNumberOfThreads,
Set<Object> writeManagerThreadPrimaryKeysWithChangesToBeMerged,
String waitingToReleaseDeferredLocksJustification) {
// (a) Build a base overview summary of the thread state
StringWriter writer = new StringWriter();
String threadName = thread.getName();
// (i) A base summary about the current thread
// is the thread waiting to acquire a lock or is it waiting to release deferred locks
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_resources_acquired_deferred_1", new Object[] {currentThreadNumber, totalNumberOfThreads, thread.getName(), threadWaitingToReleaseDeferredLocks}));
// (iii) Information is this is a thread in the process of trying to acquire for writing a cache key
if (waitingOnAcquireCacheKeys != null && !waitingOnAcquireCacheKeys.isEmpty()) {
for (ConcurrencyManager waitingOnAcquireCacheKey : waitingOnAcquireCacheKeys) {
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_resources_acquired_deferred_2", new Object[] {createToStringExplainingOwnedCacheKey(waitingOnAcquireCacheKey)}));
}
} else {
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_resources_acquired_deferred_3"));
}
// (iv) Information is this is a thread in the process of trying to acquire for reading a cache key
if (waitingOnAcquireReadCacheKey != null) {
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_resources_acquired_deferred_4", new Object[] {createToStringExplainingOwnedCacheKey(waitingOnAcquireReadCacheKey)}));
} else {
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_resources_acquired_deferred_5"));
}
// (v) if the thread is stuck in the write lock manager trying to acquire all write locks to commit and merge
// changes to the shared
// cache this information might be interesting
boolean currentThreadIsTryingCommitToSharedCacheChanges = writeManagerThreadPrimaryKeysWithChangesToBeMerged != null
&& !writeManagerThreadPrimaryKeysWithChangesToBeMerged.isEmpty();
if (currentThreadIsTryingCommitToSharedCacheChanges) {
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_resources_acquired_deferred_6", new Object[] {writeManagerThreadPrimaryKeysWithChangesToBeMerged.toString()}));
} else {
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_resources_acquired_deferred_7"));
}
// Start dumping information about the deferred lock and read lock manager of this thread
// (b) Add information about the cache keys where the current thread was set as actively owning
writer.write(ConcurrencyUtil.SINGLETON.createStringWithSummaryOfActiveLocksOnThread(lockManager, threadName));
// (c) Now very interesting as well are all of the objects that current thread could not acquire the deferred locks are essential
writer.write(createStringWithSummaryOfDeferredLocksOnThread(lockManager, threadName));
// (d) On the topic of the defferred locks we can also try to do better and explain why the algorithm
// keeps returning false that the build object is not yet complete
if (waitingToReleaseDeferredLocksJustification != null && waitingToReleaseDeferredLocksJustification.length() > 0) {
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_resources_acquired_deferred_8", new Object[] {waitingToReleaseDeferredLocksJustification}));
} else {
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_resources_acquired_deferred_9"));
}
// (e) Add information about all cache keys te current thread acquired with READ permission
writer.write(createStringWithSummaryOfReadLocksAcquiredByThread(readLockManager, threadName));
writer.write(TraceLocalization.buildMessage("concurrency_util_create_information_all_resources_acquired_deferred_10", new Object[] {currentThreadNumber, totalNumberOfThreads}));
return writer.toString();
}
/**
* Clone the static map of the concurrency manager that tells us about threads waiting to acquire locks.
*
* @param mapThreadToWaitOnAcquireOriginal
* the original map we want to clone
* @return a cloned map
*/
public static Map<Thread, ConcurrencyManager> cloneMapThreadToWaitOnAcquire(Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireOriginal) {
return new HashMap<>(mapThreadToWaitOnAcquireOriginal);
}
/**
* Clone the map of the method names that tells us justification where threads acquire locks.
*
* @param mapThreadToWaitOnAcquireOriginal
* the original map we want to clone
* @return a cloned map
*/
public static Map<Thread, String> cloneMapThreadToMethodName(Map<Thread, String> mapThreadToWaitOnAcquireOriginal) {
return new HashMap<>(mapThreadToWaitOnAcquireOriginal);
}
/**
* Clone the static map of the concurrency manager that tells us about threads waiting to acquire locks.
*
* @param mapThreadToWaitOnAcquireInsideWriteLockManagerOriginal
* the original map we want to clone
* @return a cloned map
*/
public static Map<Thread, Set<ConcurrencyManager>> cloneMapThreadToWaitOnAcquireInsideWriteLockManagerOriginal(
Map<Thread, Set<ConcurrencyManager>> mapThreadToWaitOnAcquireInsideWriteLockManagerOriginal) {
Map<Thread, Set<ConcurrencyManager>> result = new HashMap<>();
// this iterator is safe because the original map is a concurrent hashmap so the iterator should not blow up
for (Map.Entry<Thread, Set<ConcurrencyManager>> entry : mapThreadToWaitOnAcquireInsideWriteLockManagerOriginal.entrySet()) {
Set<ConcurrencyManager> clonedSet = new HashSet<>(entry.getValue());
result.put(entry.getKey(), clonedSet);
}
return result;
}
/**
* We have two maps we are using to trace threads that are stuck acquiring locks.
* One map is found in the concurrency manager the other in the write lock manager.
* When we start dumping information we only care about working with one and only one map.
* Therefore we merge the two maps together since semantically they both mean the exact same thing:
* a thread A wants a cachekey B for writing and is not getting it.
*
* @param mapThreadToWaitOnAcquireInsideWriteLockManagerClone
* this is the map we want o enrich
* @param mapThreadToWaitOnAcquireClone
* this is the map whose entries we want to copy into the map to enrich
*/
public static void enrichMapThreadToWaitOnAcquireInsideWriteLockManagerClone(
Map<Thread, Set<ConcurrencyManager>> mapThreadToWaitOnAcquireInsideWriteLockManagerClone, Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireClone ) {
// (a) Loop over each of the threads the map of mapThreadToWaitOnAcquireClone
// and add the cache keys threads are waiting for into the corresponding entery of the
// mapThreadToWaitOnAcquireInsideWriteLockManagerClone
for (Map.Entry<Thread, ConcurrencyManager> entry : mapThreadToWaitOnAcquireClone.entrySet()) {
Thread currentThread = entry.getKey();
if(!mapThreadToWaitOnAcquireInsideWriteLockManagerClone.containsKey(currentThread)) {
mapThreadToWaitOnAcquireInsideWriteLockManagerClone.put(currentThread, new HashSet<>());
}
Set<ConcurrencyManager> cacheKeys = mapThreadToWaitOnAcquireInsideWriteLockManagerClone.get(currentThread);
cacheKeys.add(entry.getValue());
}
}
/**
* A set of threads that are at the end of object building and are waiting for the deferred locks to be resolved.
*
* @param setThreadWaitingToReleaseDeferredLocksOriginal
* the original set of threads that are waiting for deferred locks to be resolved.
* @return A cloned has set of threads waiting for their deferred locks to be resolved.
*/
public static Set<Thread> cloneSetThreadsThatAreCurrentlyWaitingToReleaseDeferredLocks(
Set<Thread> setThreadWaitingToReleaseDeferredLocksOriginal) {
return new HashSet<>(setThreadWaitingToReleaseDeferredLocksOriginal);
}
/**
* Clone the information about threads that are in the write lock manager trying to commit and the object ids they
* are holding with some arbitrary changes.
*
* @param mapThreadToObjectIdWithWriteLockManagerChangesOriginal
* map of thread to the primary keys of of objects changed by a transaction in the commit phase. This is
* the original map grabbed from the WriteLockManager.
* @return a cloned map of thread to object id primary keys that a thread committing might have changed.
*/
public static Map<Thread, Set<Object>> cloneMapThreadToObjectIdWithWriteLockManagerChanges(
Map<Thread, Set<Object>> mapThreadToObjectIdWithWriteLockManagerChangesOriginal) {
Map<Thread, Set<Object>> result = new HashMap<>();
for (Map.Entry<Thread, Set<Object>> currentEntry : mapThreadToObjectIdWithWriteLockManagerChangesOriginal.entrySet()) {
result.put(currentEntry.getKey(), new HashSet<>(currentEntry.getValue()));
}
return result;
}
/**
* To facilitate algorithms that want to dump a snapshot of the current state of the concurrency manager or to start
* a hunt for dead locks this api faciliates the boostraping logic of such algorithms by giving the algorithm a
* stable clone of the map of read locks that we know will not change throughout the time the algorithm is running.
*
* @param readLockManagersOriginal
* This the original map of read locks referred by the concurrency manager. This is a very bad platform
* to work with because if for whatever reason not all threads are frozen and some are actualy managing
* to complete their transactions the contents of this map are systematically changing with threds being
* added in and removed.
* @return A clone of the readLockManagersOriginal. Essentially the map instance returned is new and independent and
* the values {@link ReadLockManager} are also clones and independent. The only thing that is
* not cloned here - whose state could be changing - are the cache key themselves. The cache keys pointed by
* the vector {@link ReadLockManager#getReadLocks()} are the original values. So our clone
* from the read lock manager is not a perfectly stable clone. It will not be blowing up telling us
* concurrent access modification when we loop through the vector. But no one can guarnate the number of
* readers on the cache key stays the same nor that the active thread on a cache key stays the same... Those
* values can definitely be fluctuating (not ideal ... but it would be quite hard to get better than this).
*/
public Map<Thread, ReadLockManager> cloneReadLockManagerMap(Map<Thread, ReadLockManager> readLockManagersOriginal) {
// (a) Start by safeguarding the keys of the map we want to clone
// (e.g. avoid the risk of concurrent modification exception while looping over a keyset)
List<Thread> mapKeys = new ArrayList<>(readLockManagersOriginal.keySet());
// (b) start the the cloning process
Map<Thread, ReadLockManager> cloneResult = new HashMap<>();
for (Thread currentKey : mapKeys) {
ReadLockManager readLockManagerOriginal = readLockManagersOriginal.get(currentKey);
if (readLockManagerOriginal != null) {
ReadLockManager readLockManagerClone = readLockManagerOriginal.clone();
cloneResult.put(currentKey, readLockManagerClone);
} else {
// most likely the current thread has just finished its work
// and is no longer to be found in the original map
}
}
// (c) The caller of this method can do with it whatever it wants because no one will be modifying this map
// nor the contained
return cloneResult;
}
/**
* The exact same thing as the {@link #cloneReadLockManagerMap(Map)} but the map we are cloning here is the one of
* threads to deferred locks
*
* @param deferredLockManagersOriginal
* the original map taken from the conrruency manager itself
* @return A clone of that map that is a relatively stable data structure to work with since no new threads will
* register in or out in the map nor will the DeferredLockManager values be changing. As for the read lock
* manager we have no assurance as to what is happening with the cache keys themselves refered by the
* {@link DeferredLockManager} values, the cache keys are always changing their metadata as new threads come
* in to do work or finish doing work. So it is not a perfect snapshot of the state of the system, but it is
* as close as we can get.
*/
public Map<Thread, DeferredLockManager> cloneDeferredLockManagerMap(Map<Thread, DeferredLockManager> deferredLockManagersOriginal) {
// (a) Start by safeguarding the keys of the map we want to clone
// (e.g. avoid the risk of concurrent modification exception while looping over a keyset)
List<Thread> mapKeys = new ArrayList<>(deferredLockManagersOriginal.keySet());
// (b) start the the cloning process
Map<Thread, DeferredLockManager> cloneResult = new HashMap<>();
for (Thread currentKey : mapKeys) {
DeferredLockManager deferredLockManagerOriginal = deferredLockManagersOriginal.get(currentKey);
if (deferredLockManagerOriginal != null) {
DeferredLockManager deferredLockManagerClone = cloneDeferredLockManager(deferredLockManagerOriginal);
cloneResult.put(currentKey, deferredLockManagerClone);
} else {
// most likely the current thread has just finished its work
// and is no longer to be found in the original map
}
}
// (c) The caller of this method can do with it whatever it wants because no one will be modifying this map
// nor the contained
return cloneResult;
}
/**
* Clone an original {@link DeferredLockManager} so that our algorithms of state dump or dead lock search can safely
* work ina stable model state that is not constantly changing.
*
* @param deferredLockManagerOriginal
* an object that is originating from the map of thread to deferred locks from the concurrency manager
* class. We do not want to be carrying around the original object while try to make a dump/snapshot of
* the current state of the concurrency manager since these objects are always mutating. Locks are being
* acquired and released etc... All the tiem. The only objest thta will be stable are those of threads
* involved ina dead lock. And those are the threads that matter the most to us anyway.
* @return a cloned deferred lock manager. The newly created deferred lock manager will have its vectors of cache
* keys holding references the same cache keys as the original object. The cache keys themselves are not
* cloned. That measn that the DeferredLockManager will be immuatable in terms of its vectors and held
* references. But the objects it refers to (e.g. cache keys) can be mutating all the time if new readers or
* active threads arrive.
*/
@SuppressWarnings("rawtypes")
public DeferredLockManager cloneDeferredLockManager(DeferredLockManager deferredLockManagerOriginal) {
// (a) Start by cloning from the original the two vectors of cache keys is administers
Vector cloneOfActiveLocks = (Vector) deferredLockManagerOriginal.getActiveLocks().clone();
Vector cloneOfDeferredLocks = (Vector) deferredLockManagerOriginal.getDeferredLocks().clone();
// (b) Build our clone object
DeferredLockManager deferredLockManagerClone = new DeferredLockManager();
deferredLockManagerClone.setIsThreadComplete(deferredLockManagerOriginal.isThreadComplete());
// NOTE: the DeferredLockManager follows a very bad practice
// it gives direct acess to its internal state from outside
// it gives us direct access to its referred lists
// so the internal private state of the deferredLockManager can be modified directly from the outisde
// by anybody...
// but we use the apis we have access to.
deferredLockManagerClone.getActiveLocks().addAll(cloneOfActiveLocks);
deferredLockManagerClone.getDeferredLocks().addAll(cloneOfDeferredLocks);
return deferredLockManagerClone;
}
/**
* Enrich the mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey by setting on the cache keys the threads
* that are stuck trying to acquire the cache key.
*
* @param mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey
* the map we are trying to enirhc with additional information
* @param unifiedMapOfThreadsStuckTryingToAcquireWriteLock
* a map telling us about threads that at a certain point in time were not progressing anywhere because
* they were waiting to acquire a write lock. These are threads either stuck on the concurrency manager
* or in the write lock manager during a transaction commmit
*
*
*/
public void enrichMapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKeyInfoThreadsStuckOnAcquire(
Map<ConcurrencyManager, CacheKeyToThreadRelationships> mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey,
Map<Thread, Set<ConcurrencyManager>> unifiedMapOfThreadsStuckTryingToAcquireWriteLock) {
// (a) Loop over each thread that registered itself as being waiting to lock a cache key
for (Map.Entry<Thread, Set<ConcurrencyManager>> currentEntry : unifiedMapOfThreadsStuckTryingToAcquireWriteLock
.entrySet()) {
Thread currentThread = currentEntry.getKey();
for (ConcurrencyManager cacheKeyThreadIsWaitingToAcquire : currentEntry.getValue()) {
CacheKeyToThreadRelationships dto = get(cacheKeyThreadIsWaitingToAcquire, mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey);
dto.addThreadsKnownToBeStuckTryingToAcquireLock(currentThread);
}
}
}
/**
* Enrich the mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey by setting on the cache keys the threads
* that are stuck trying to acquire the cache key with a read lock. These are threads stuck on the
* {@link org.eclipse.persistence.internal.helper.ConcurrencyManager#acquireReadLock()}
*
* @param mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey
* the map we are trying to enirhc with additional information
* @param mapThreadToWaitOnAcquireReadLockClone
* a map telling us about threads that at a certain point in time were not progressing anywhere because
* they were waiting to acquire a lock.
*
*
*/
public void enrichMapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKeyInfoThreadsStuckOnAcquireLockForReading(
Map<ConcurrencyManager, CacheKeyToThreadRelationships> mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey,
Map<Thread, ConcurrencyManager> mapThreadToWaitOnAcquireReadLockClone) {
// (a) Loop over each thread that registered itself as being waiting to lock a cache key
for (Map.Entry<Thread, ConcurrencyManager> currentEntry : mapThreadToWaitOnAcquireReadLockClone.entrySet()) {
Thread currentThread = currentEntry.getKey();
ConcurrencyManager cacheKeyThreadIsWaitingToAcquire = currentEntry.getValue();
CacheKeyToThreadRelationships dto = get(cacheKeyThreadIsWaitingToAcquire,
mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey);
dto.addThreadsKnownToBeStuckTryingToAcquireLockForReading(currentThread);
}
}
/**
* Enrich the mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey based on the read locks
*
* @param mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey
* a map whose metadata we need to enrich
* @param readLockManagerMapClone
* map cloned from the original map and that gives us a snapshot of threads that acquired read locks
*/
public void enrichMapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKeyInfoAboutReadLocks(
Map<ConcurrencyManager, CacheKeyToThreadRelationships> mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey,
Map<Thread, ReadLockManager> readLockManagerMapClone) {
// (a) Loop over each thread that is regisered as having acquired read locks
for (Map.Entry<Thread, ReadLockManager> currentEntry : readLockManagerMapClone.entrySet()) {
Thread currentThread = currentEntry.getKey();
ReadLockManager currentValue = currentEntry.getValue();
// (b) loop over each read lock acquired by the current thread
// enrich the map of cache key to thread doing something in respect to the cache key
for (ConcurrencyManager cacheKeyAcquiredReadLock : currentValue.getReadLocks()) {
CacheKeyToThreadRelationships dto = get(cacheKeyAcquiredReadLock,
mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey);
dto.addThreadsThatAcquiredReadLock(currentThread);
}
}
}
/**
* Enrich our map map of cache key to threads having a relationship with that object in regards to active locks on
* the cache key and deferred locks on the cache key
*
* @param mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey
* the map we want to enrich with more information
* @param deferredLockManagerMapClone
* the cloned map with information about threads and their deferred locks.
*/
public void enrichMapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKeyInfoAboutActiveAndDeferredLocks(
Map<ConcurrencyManager, CacheKeyToThreadRelationships> mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey,
Map<Thread, DeferredLockManager> deferredLockManagerMapClone) {
// (a) Loop over each thread that has a deferred lock manager
for (Map.Entry<Thread, DeferredLockManager> currentEntry : deferredLockManagerMapClone.entrySet()) {
Thread currentThread = currentEntry.getKey();
DeferredLockManager currentValue = currentEntry.getValue();
// (b) First we focus on the active locks owned by the thread
// enrich the map of cache key to thread doing something in respect to the cache key
for (Object activeLockObj : currentValue.getActiveLocks()) {
ConcurrencyManager activeLock = (ConcurrencyManager) activeLockObj;
CacheKeyToThreadRelationships dto = get(activeLock, mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey);
dto.addThreadsThatAcquiredActiveLock(currentThread);
}
// (c) Now we go over the defferred locks on this thread
// (e.g. object locks that it could not acquire because some other thread was active at the time owning the
// lock)
for (Object deferredLockObj : currentValue.getDeferredLocks()) {
ConcurrencyManager deferredLock = (ConcurrencyManager) deferredLockObj;
CacheKeyToThreadRelationships dto = get(deferredLock, mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey);
dto.addThreadsThatAcquiredDeferredLock(currentThread);
}
}
}
/**
* Helper method to make sure we never get null dto from the
* mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey.
*
* @param cacheKey
* the cache key we are search for
* @param mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey
* the map of cache key to concurrency manager locking metadata
* @return never returls null. If the cache key is not yet in the map a ney entry is returned.
*/
protected CacheKeyToThreadRelationships get(ConcurrencyManager cacheKey,
Map<ConcurrencyManager, CacheKeyToThreadRelationships> mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey) {
if (!mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey.containsKey(cacheKey)) {
mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey.put(cacheKey,
new CacheKeyToThreadRelationships(cacheKey));
}
return mapOfCacheKeyToDtosExplainingThreadExpectationsOnCacheKey.get(cacheKey);
}
/**
* If when we are decrement the counter of number of readers on a cache key we find ourselves lacking the read lock
* manager at the time of the decrement we want to log a big fat error on the server log protecting that the current
* thread is misbehaving.
*
* @param currentNumberOfReaders
* the current count of readers on the cache key about to be decremented
* @param decrementedNumberOfReaders
* the number of readers of the cache key if we subtract one reader
* @param cacheKey
* the cache key that is about to suffer a decrement on the number of readers
*/
public String readLockManagerProblem01CreateLogErrorMessageToIndicateThatCurrentThreadHasNullReadLockManagerWhileDecrementingNumberOfReaders(
final int currentNumberOfReaders, final int decrementedNumberOfReaders, ConcurrencyManager cacheKey) {
Thread currentThread = Thread.currentThread();
StringWriter writer = new StringWriter();
writer.write(TraceLocalization.buildMessage("concurrency_util_read_lock_manager_problem01", new Object[] {currentThread.getName(), currentNumberOfReaders, decrementedNumberOfReaders,
ConcurrencyUtil.SINGLETON.createToStringExplainingOwnedCacheKey(cacheKey), enrichGenerateThreadDumpForCurrentThread(), new Date()}));
AbstractSessionLog.getLog().log(SessionLog.SEVERE, SessionLog.CACHE, writer.toString(), new Object[] {}, false);
return writer.toString();
}
public String readLockManagerProblem02ReadLockManageHasNoEntriesForThread(ConcurrencyManager cacheKey, long threadId) {
Thread currentThread = Thread.currentThread();
StringWriter writer = new StringWriter();
writer.write(TraceLocalization.buildMessage("concurrency_util_read_lock_manager_problem02", new Object[] {currentThread.getName(), SINGLETON.createToStringExplainingOwnedCacheKey(cacheKey),
threadId, enrichGenerateThreadDumpForCurrentThread(), ConversionManager.getDefaultManager().convertObject(new Date(), String.class).toString()}));
// We do log immediately the error as we spot it
AbstractSessionLog.getLog().log(SessionLog.SEVERE, SessionLog.CACHE, writer.toString(), new Object[] {}, false);
// we also return the error message we just logged to added it to our tracing permanently
return writer.toString();
}
public String readLockManagerProblem03ReadLockManageHasNoEntriesForThread(ConcurrencyManager cacheKey, long threadId) {
Thread currentThread = Thread.currentThread();
StringWriter writer = new StringWriter();
writer.write(TraceLocalization.buildMessage("concurrency_util_read_lock_manager_problem03", new Object[] {currentThread.getName(), SINGLETON.createToStringExplainingOwnedCacheKey(cacheKey),
threadId, enrichGenerateThreadDumpForCurrentThread(), ConversionManager.getDefaultManager().convertObject(new Date(), String.class).toString()}));
// We do log immediately the error as we spot it
AbstractSessionLog.getLog().log(SessionLog.SEVERE, SessionLog.CACHE, writer.toString(), new Object[] {}, false);
// we also return the error message we just logged to added it to our tracing permanently
return writer.toString();
}
/**
* The concurrency managers about to acquire a cache key. And since we have been suffering from cache corruption on
* the acquire read locks we need to collect a lot more information about the time of acquisition of a read lock.
*
* @param concurrencyManager
* the cache key we are about to increment and acquire for reading
* @return object that have all the context information to allow us to know when and where
* exactly this key acquisition took place.
*/
public ReadLockAcquisitionMetadata createReadLockAcquisitionMetadata(ConcurrencyManager concurrencyManager) {
final boolean isAllowTakingStackTraceDuringReadLockAcquisition = isAllowTakingStackTraceDuringReadLockAcquisition();
String currentThreadStackTraceInformation = TraceLocalization.buildMessage("concurrency_util_read_lock_acquisition_metadata");
long currentThreadStackTraceInformationCpuTimeCostMs = 0l;
if (isAllowTakingStackTraceDuringReadLockAcquisition) {
long startTimeMillis = System.currentTimeMillis();
currentThreadStackTraceInformation = enrichGenerateThreadDumpForCurrentThread();
long endTimeMillis = System.currentTimeMillis();
currentThreadStackTraceInformationCpuTimeCostMs = endTimeMillis - startTimeMillis;
}
int numberOfReadersOnCacheKeyBeforeIncrementingByOne = concurrencyManager.getNumberOfReaders();
// data in ReadLockAcquisitionMetadata are immutable it reflects an accurate snapshot of the time of acquisition
return new ReadLockAcquisitionMetadata(concurrencyManager, numberOfReadersOnCacheKeyBeforeIncrementingByOne,
currentThreadStackTraceInformation, currentThreadStackTraceInformationCpuTimeCostMs);
}
private int getIntProperty(final String key, final int defaultValue) {
String value = (PrivilegedAccessHelper.shouldUsePrivilegedAccess()) ?
AccessController.doPrivileged(new PrivilegedGetSystemProperty(key, String.valueOf(defaultValue)))
: System.getProperty(key, String.valueOf(defaultValue));
if (value != null) {
try {
return Integer.parseInt(value.trim());
} catch (Exception ignoreE) {
return defaultValue;
}
}
return defaultValue;
}
private long getLongProperty(final String key, final long defaultValue) {
String value = (PrivilegedAccessHelper.shouldUsePrivilegedAccess()) ?
AccessController.doPrivileged(new PrivilegedGetSystemProperty(key, String.valueOf(defaultValue)))
: System.getProperty(key, String.valueOf(defaultValue));
if (value != null) {
try {
return Long.parseLong(value.trim());
} catch (Exception ignoreE) {
return defaultValue;
}
}
return defaultValue;
}
private boolean getBooleanProperty(final String key, final boolean defaultValue) {
String value = (PrivilegedAccessHelper.shouldUsePrivilegedAccess()) ?
AccessController.doPrivileged(new PrivilegedGetSystemProperty(key, String.valueOf(defaultValue)))
: System.getProperty(key, String.valueOf(defaultValue));
if (value != null) {
try {
return Boolean.parseBoolean(value.trim());
} catch (Exception ignoreE) {
return defaultValue;
}
}
return defaultValue;
}
}
|