Skip to content

Commit 08fdd8b

Browse files
rishabhdaimRishabh Kumar
authored and
andreeastroe96
committed
OAK-11401 : increased audit log level for VGC (apache#2024)
Co-authored-by: Rishabh Kumar <diam@adobe.com>
1 parent ddaf749 commit 08fdd8b

File tree

1 file changed

+25
-31
lines changed

1 file changed

+25
-31
lines changed

‎oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/VersionGarbageCollector.java‎

Lines changed: 25 additions & 31 deletions
Original file line numberDiff line numberDiff line change
@@ -1269,8 +1269,8 @@ private void combineInternalPropRemovals(final NodeDocument doc, final UpdateOp
12691269

12701270
// update the deleted properties count Map to calculate the total no. of deleted properties
12711271
int totalDeletedSystemPropsCount = deletedInternalPropsCountMap.merge(doc.getId(), deletedSystemPropsCount, Integer::sum);
1272-
if (AUDIT_LOG.isDebugEnabled() && totalDeletedSystemPropsCount > 0) {
1273-
AUDIT_LOG.debug("<Collected> [{}] internal prop revs in [{}] mode [{}]", totalDeletedSystemPropsCount, doc.getId(), fullGcMode);
1272+
if (AUDIT_LOG.isInfoEnabled() && totalDeletedSystemPropsCount > 0) {
1273+
AUDIT_LOG.info("<Collected> [{}] internal prop revs in [{}] mode [{}]", totalDeletedSystemPropsCount, doc.getId(), fullGcMode);
12741274
}
12751275
}
12761276
}
@@ -1348,9 +1348,7 @@ private boolean isDeletedOrOrphanedNode(final NodeState traversedState, final Pa
13481348
orphanOrDeletedRemovalPathMap.put(doc.getId(), doc.getPath());
13491349
fullGCStats.candidateDocuments(GCPhase.FULL_GC_COLLECT_ORPHAN_NODES, 1);
13501350

1351-
if (AUDIT_LOG.isDebugEnabled()) {
1352-
AUDIT_LOG.debug("<Collected> [{}] orphaned node", doc.getId());
1353-
}
1351+
AUDIT_LOG.info("<Collected> [{}] orphaned node in mode [{}]", doc.getId(), fullGcMode);
13541352

13551353
phases.stop(GCPhase.FULL_GC_COLLECT_ORPHAN_NODES);
13561354
return true;
@@ -1388,8 +1386,8 @@ private void collectDeletedProperties(final NodeDocument doc, final GCPhases pha
13881386
deletedPropsCountMap.put(doc.getId(), deletedPropsCount);
13891387
fullGCStats.candidateProperties(GCPhase.FULL_GC_COLLECT_PROPS, deletedPropsCount);
13901388

1391-
if (AUDIT_LOG.isDebugEnabled() && deletedPropsCount > 0) {
1392-
AUDIT_LOG.debug("<Collected> [{}] deleted props in [{}]", deletedPropsCount, doc.getId());
1389+
if (AUDIT_LOG.isInfoEnabled() && deletedPropsCount > 0) {
1390+
AUDIT_LOG.info("<Collected> [{}] deleted props in [{}]. Property Names [{}]", deletedPropsCount, doc.getId(), updateOp.getChanges().keySet());
13931391
}
13941392
phases.stop(GCPhase.FULL_GC_COLLECT_PROPS);
13951393
}
@@ -1427,8 +1425,8 @@ private void collectUnmergedBranchCommits(final NodeDocument doc, final GCPhases
14271425
olderUnmergedBranchCommits.forEach(bcRevision -> removeUnmergedBCRevision(bcRevision, doc, updateOp));
14281426
deletedUnmergedBCSet.addAll(olderUnmergedBranchCommits);
14291427

1430-
if (AUDIT_LOG.isDebugEnabled()) {
1431-
AUDIT_LOG.debug("<Collected> [{}] unmerged branch commits in [{}]", olderUnmergedBranchCommits.size(), doc.getId());
1428+
if (AUDIT_LOG.isInfoEnabled()) {
1429+
AUDIT_LOG.info("<Collected> [{}] unmerged branch commits in [{}]", olderUnmergedBranchCommits.size(), doc.getId());
14321430
}
14331431

14341432
// now for any of the handled system properties (the normal properties would
@@ -1459,8 +1457,8 @@ private void collectUnmergedBranchCommits(final NodeDocument doc, final GCPhases
14591457
int totalDeletedSystemPropsCount = deletedInternalPropsCountMap.merge(doc.getId(), deletedSystemPropsCount, Integer::sum);
14601458
fullGCStats.candidateInternalRevisions(GCPhase.FULL_GC_COLLECT_UNMERGED_BC, totalDeletedSystemPropsCount);
14611459

1462-
if (AUDIT_LOG.isDebugEnabled() && totalDeletedSystemPropsCount > 0) {
1463-
AUDIT_LOG.debug("<Collected> [{}] internal prop revs in [{}] mode [{}]", totalDeletedSystemPropsCount, doc.getId(), fullGcMode);
1460+
if (AUDIT_LOG.isInfoEnabled() && totalDeletedSystemPropsCount > 0) {
1461+
AUDIT_LOG.info("<Collected> [{}] internal prop revs in [{}] mode [{}]", totalDeletedSystemPropsCount, doc.getId(), fullGcMode);
14641462
}
14651463
}
14661464
phases.stop(GCPhase.FULL_GC_COLLECT_UNMERGED_BC);
@@ -1619,8 +1617,8 @@ private void removeUnmergedBCRevision(final Revision unmergedBCRevision, final N
16191617
fullGCStats.candidateRevisions(GCPhase.FULL_GC_COLLECT_UNMERGED_BC, revEntriesCount);
16201618
fullGCStats.candidateInternalRevisions(GCPhase.FULL_GC_COLLECT_UNMERGED_BC, internalRevEntriesCount);
16211619

1622-
if (AUDIT_LOG.isDebugEnabled() && (revEntriesCount > 0 || internalRevEntriesCount > 0)) {
1623-
AUDIT_LOG.debug("<Collected> [{}] prop revs, [{}] internal prop revs in [{}] mode [{}]", revEntriesCount, internalRevEntriesCount, doc.getId(), fullGcMode);
1620+
if (AUDIT_LOG.isInfoEnabled() && (revEntriesCount > 0 || internalRevEntriesCount > 0)) {
1621+
AUDIT_LOG.info("<Collected> [{}] prop revs, [{}] internal prop revs in [{}] mode [{}]", revEntriesCount, internalRevEntriesCount, doc.getId(), fullGcMode);
16241622
}
16251623

16261624
}
@@ -1640,8 +1638,8 @@ private void collectRevisionsOlderThan24hAndBetweenCheckpoints(final NodeDocumen
16401638
if (intRevsDiff > 0) {
16411639
deletedInternalPropRevsCountMap.merge(doc.getId(), intRevsDiff, Integer::sum);
16421640
}
1643-
if (AUDIT_LOG.isDebugEnabled() && (revsDiff > 0 || intRevsDiff > 0)) {
1644-
AUDIT_LOG.debug("<Collected> [{}] prop revs, [{}] internal prop revs in [{}] mode [{}]", revsDiff, intRevsDiff, doc.getId(), fullGcMode);
1641+
if (AUDIT_LOG.isInfoEnabled() && (revsDiff > 0 || intRevsDiff > 0)) {
1642+
AUDIT_LOG.info("<Collected> [{}] prop revs, [{}] internal prop revs in [{}] mode [{}]", revsDiff, intRevsDiff, doc.getId(), fullGcMode);
16451643
}
16461644
fullGCStats.candidateRevisions(GCPhase.FULL_GC_COLLECT_OLD_REVS, revsDiff);
16471645
fullGCStats.candidateInternalRevisions(GCPhase.FULL_GC_COLLECT_OLD_REVS, intRevsDiff);
@@ -1690,8 +1688,8 @@ private void collectUnusedPropertyRevisions(final NodeDocument doc,
16901688
deletedInternalPropRevsCountMap.merge(doc.getId(), deletedInternalRevsCount, Integer::sum);
16911689
}
16921690

1693-
if (AUDIT_LOG.isDebugEnabled() && deletedTotalRevsCount > 0) {
1694-
AUDIT_LOG.debug("<Collected> [{}] prop revs, [{}] internal prop revs in [{}] mode [{}]", deletedUserRevsCount, deletedInternalRevsCount, doc.getId(), fullGcMode);
1691+
if (AUDIT_LOG.isInfoEnabled() && deletedTotalRevsCount > 0) {
1692+
AUDIT_LOG.info("<Collected> [{}] prop revs, [{}] internal prop revs in [{}] mode [{}]", deletedUserRevsCount, deletedInternalRevsCount, doc.getId(), fullGcMode);
16951693
}
16961694
fullGCStats.candidateRevisions(GCPhase.FULL_GC_COLLECT_OLD_REVS, deletedUserRevsCount);
16971695
fullGCStats.candidateInternalRevisions(GCPhase.FULL_GC_COLLECT_OLD_REVS, deletedInternalRevsCount);
@@ -1924,18 +1922,18 @@ public void close() {
19241922
public void removeGarbage(final VersionGCStats stats) {
19251923

19261924
if (updateOpList.isEmpty() && orphanOrDeletedRemovalMap.isEmpty()) {
1927-
if (log.isDebugEnabled() || isFullGCDryRun) {
1928-
log.debug("Skipping removal of Full garbage, cause no garbage detected");
1925+
if (log.isInfoEnabled() || isFullGCDryRun) {
1926+
log.info("Skipping removal of Full garbage, cause no garbage detected");
19291927
}
19301928
return;
19311929
}
19321930

19331931
monitor.info("Proceeding to update [{}] documents", updateOpList.size());
19341932

1935-
if (AUDIT_LOG.isDebugEnabled() || isFullGCDryRun) {
1933+
if (AUDIT_LOG.isInfoEnabled() || isFullGCDryRun) {
19361934
String updateIds = updateOpList.stream().map(UpdateOp::getId).collect(joining(", "));
19371935
String orphanIds = join(", ", orphanOrDeletedRemovalMap.keySet());
1938-
log.debug("Performing batch update of ids [{}] and removal of orphan ids [{}]", updateIds, orphanIds);
1936+
AUDIT_LOG.info("Performing batch update of ids [{}] and removal of orphan ids [{}]", updateIds, orphanIds);
19391937
}
19401938

19411939
if (cancel.get()) {
@@ -1969,9 +1967,7 @@ public void removeGarbage(final VersionGCStats stats) {
19691967
if (!verifyViaTraversedState(traversedState, traversedParent, newDoc)) {
19701968
// verification failure
19711969
// let's skip this document
1972-
if (log.isDebugEnabled()) {
1973-
log.debug("removeGarbage.verify : verifyViaTraversedState failed for [{}]", newDoc.getId());
1974-
}
1970+
log.warn("removeGarbage.verify : verifyViaTraversedState failed for [{}]", newDoc.getId());
19751971
it.remove();
19761972
stats.skippedFullGCDocsCount++;
19771973
}
@@ -1993,9 +1989,7 @@ public void removeGarbage(final VersionGCStats stats) {
19931989
if (!verifyDeletion(traversedState)) {
19941990
// verification failure
19951991
// let's skip this document
1996-
if (log.isDebugEnabled()) {
1997-
log.debug("removeGarbage.verify : verifyDeletion failed for [{}]", e.getKey());
1998-
}
1992+
log.warn("removeGarbage.verify : verifyDeletion failed for [{}]", e.getKey());
19991993
it.remove();
20001994
stats.skippedFullGCDocsCount++;
20011995
}
@@ -2016,8 +2010,8 @@ public void removeGarbage(final VersionGCStats stats) {
20162010
stats.deletedDocGCCount += removedSize;
20172011
stats.deletedOrphanNodesCount += removedSize;
20182012

2019-
if (AUDIT_LOG.isDebugEnabled()) {
2020-
AUDIT_LOG.debug("<delete> [{}] documents (from intended {})", removedSize, orphanOrDeletedRemovalMap.size());
2013+
if (AUDIT_LOG.isInfoEnabled()) {
2014+
AUDIT_LOG.info("<delete> [{}] documents (from intended {})", removedSize, orphanOrDeletedRemovalMap.size());
20212015
}
20222016

20232017
// save stats
@@ -2044,8 +2038,8 @@ public void removeGarbage(final VersionGCStats stats) {
20442038
stats.deletedInternalPropRevsCount += deletedInternalRevEntriesCount;
20452039
stats.deletedUnmergedBCCount += deletedUnmergedBCSet.size();
20462040

2047-
if (log.isDebugEnabled()) {
2048-
log.debug("Updated [{}] docs, deleted [{}] props, deleted [{}] unmergedBCs, deleted [{}] internal Props, deleted [{}] prop revs, deleted [{}] internal prop revs",
2041+
if (log.isInfoEnabled()) {
2042+
log.info("Updated [{}] docs, deleted [{}] props, deleted [{}] unmergedBCs, deleted [{}] internal Props, deleted [{}] prop revs, deleted [{}] internal prop revs",
20492043
updatedDocs, deletedProps, deletedUnmergedBCSet.size(), deletedInternalProps, deletedRevEntriesCount, deletedInternalRevEntriesCount);
20502044
}
20512045

0 commit comments

Comments
 (0)