You are viewing a plain text version of this content. The canonical link for it is here.
Posted to oak-issues@jackrabbit.apache.org by "Michael Dürig (JIRA)" <ji...@apache.org> on 2018/01/10 10:35:01 UTC
[jira] [Commented] (OAK-7132) SNFE after full compaction
[ https://issues.apache.org/jira/browse/OAK-7132?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16320033#comment-16320033 ]
Michael Dürig commented on OAK-7132:
------------------------------------
At http://svn.apache.org/viewvc?rev=1820729&view=rev I added the capability to interleave runs of full and tail compaction to {{SCIT}}.
With this I can reproduce the {{SNFE}}. It occurs right after the second run off full compaction, which is the first "non trivial" full compaction:
{noformat}
11:15:15.583 INFO [main] FileStoreBuilder.java:340 Creating file store FileStoreBuilder{version=null, directory=target/junit8157909954958580019, blobStore=null, maxFileSize=256, segmentCacheSize=256, stringCacheSize=256, templateCacheSize=64, stringDeduplicationCacheSize=15000, templateDeduplicationCacheSize=3000, nodeDeduplicationCacheSize=1048576, memoryMapping=true, gcOptions=SegmentGCOptions{paused=false, estimationDisabled=true, gcSizeDeltaEstimation=1073741824, retryCount=5, forceTimeout=3600, retainedGenerations=2, gcType=FULL}}
11:15:15.797 INFO [main] FileStore.java:215 TarMK opened at target/junit8157909954958580019, mmap=true, size=0 B (0 bytes)
11:15:15.927 INFO [main] SegmentNodeStore.java:120 Creating segment node store SegmentNodeStoreBuilder{blobStore=inline}
11:15:15.933 INFO [main] LockBasedScheduler.java:155 Initializing SegmentNodeStore with the commitFairLock option enabled.
11:15:15.976 INFO [main] SegmentCompactionIT.java:349 Scheduling FULL compaction after 2 minutes
11:17:15.978 INFO [pool-1-thread-24] SegmentCompactionIT.java:742 Running compaction
11:17:15.980 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #1: started
TarMK GC #1: started
11:17:15.980 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #1: estimation skipped because it was explicitly disabled
TarMK GC #1: estimation skipped because it was explicitly disabled
11:17:15.988 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #1: setting up a listener to cancel compaction if available memory on pool 'PS Old Gen' drops below 429.5 MB (429549158 bytes) / 15%.
TarMK GC #1: setting up a listener to cancel compaction if available memory on pool 'PS Old Gen' drops below 429.5 MB (429549158 bytes) / 15%.
11:17:15.991 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #1: available memory level 2.8 GB (2788498720 bytes) is good, expecting at least 429.5 MB (429549158 bytes)
TarMK GC #1: available memory level 2.8 GB (2788498720 bytes) is good, expecting at least 429.5 MB (429549158 bytes)
11:17:15.992 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #1: running full compaction
TarMK GC #1: running full compaction
11:17:15.992 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #1: compaction started, gc options=SegmentGCOptions{paused=false, estimationDisabled=true, gcSizeDeltaEstimation=1073741824, retryCount=5, forceTimeout=3600, retainedGenerations=2, gcType=FULL}, current generation=GCGeneration{generation=0,fullGeneration=0,isCompacted=false}, new generation=GCGeneration{generation=1,fullGeneration=1,isCompacted=true}
TarMK GC #1: compaction started, gc options=SegmentGCOptions{paused=false, estimationDisabled=true, gcSizeDeltaEstimation=1073741824, retryCount=5, forceTimeout=3600, retainedGenerations=2, gcType=FULL}, current generation=GCGeneration{generation=0,fullGeneration=0,isCompacted=false}, new generation=GCGeneration{generation=1,fullGeneration=1,isCompacted=true}
11:17:15.993 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #1: unable to estimate number of nodes for compaction, missing gc history.
TarMK GC #1: unable to estimate number of nodes for compaction, missing gc history.
11:17:15.997 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #1: found checkpoint b7e96c5a-49e6-41fa-96eb-a1d00609f3a3 created at Wed Jan 10 11:17:12 CET 2018.
TarMK GC #1: found checkpoint b7e96c5a-49e6-41fa-96eb-a1d00609f3a3 created at Wed Jan 10 11:17:12 CET 2018.
11:17:15.998 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #1: compacting checkpoints/b7e96c5a-49e6-41fa-96eb-a1d00609f3a3/root.
TarMK GC #1: compacting checkpoints/b7e96c5a-49e6-41fa-96eb-a1d00609f3a3/root.
11:17:16.317 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #1: compacting root.
TarMK GC #1: compacting root.
11:17:16.539 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #1: compaction cycle 0 completed in 547.2 ms (547 ms). Compacted e7ca06ba-1cb0-4f7a-a313-c8e91b84ae01.00000667 to 8baf69f5-ee0a-41ce-a067-d66603a21f58.00000599
TarMK GC #1: compaction cycle 0 completed in 548.1 ms (548 ms). Compacted e7ca06ba-1cb0-4f7a-a313-c8e91b84ae01.00000667 to 8baf69f5-ee0a-41ce-a067-d66603a21f58.00000599
11:17:16.546 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #1: compaction succeeded in 554.1 ms (554 ms), after 0 cycles
TarMK GC #1: compaction succeeded in 554.4 ms (554 ms), after 0 cycles
11:17:16.563 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #1: cleanup started.
TarMK GC #1: cleanup started.
11:17:16.867 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #1: cleanup marking files for deletion: none
TarMK GC #1: cleanup marking files for deletion: none
11:17:16.884 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #1: cleanup completed in 321.0 ms (320 ms). Post cleanup size is 29.5 MB (29543424 bytes) and space reclaimed 0 B (0 bytes).
TarMK GC #1: cleanup completed in 321.7 ms (321 ms). Post cleanup size is 29.5 MB (29543424 bytes) and space reclaimed 0 B (0 bytes).
11:17:16.885 INFO [pool-1-thread-24] SegmentCompactionIT.java:349 Scheduling TAIL compaction after 2 minutes
11:19:16.888 INFO [pool-1-thread-1] SegmentCompactionIT.java:742 Running compaction
11:19:16.889 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #2: started
TarMK GC #2: started
11:19:16.889 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #2: estimation skipped because it was explicitly disabled
TarMK GC #2: estimation skipped because it was explicitly disabled
11:19:16.889 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #2: setting up a listener to cancel compaction if available memory on pool 'PS Old Gen' drops below 429.5 MB (429549158 bytes) / 15%.
TarMK GC #2: setting up a listener to cancel compaction if available memory on pool 'PS Old Gen' drops below 429.5 MB (429549158 bytes) / 15%.
11:19:16.890 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #2: available memory level 2.7 GB (2720215408 bytes) is good, expecting at least 429.5 MB (429549158 bytes)
TarMK GC #2: available memory level 2.7 GB (2720215408 bytes) is good, expecting at least 429.5 MB (429549158 bytes)
11:19:16.890 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #2: running tail compaction
TarMK GC #2: running tail compaction
11:19:16.891 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #2: compaction started, gc options=SegmentGCOptions{paused=false, estimationDisabled=true, gcSizeDeltaEstimation=1073741824, retryCount=5, forceTimeout=3600, retainedGenerations=2, gcType=TAIL}, current generation=GCGeneration{generation=1,fullGeneration=1,isCompacted=false}, new generation=GCGeneration{generation=2,fullGeneration=1,isCompacted=true}
TarMK GC #2: compaction started, gc options=SegmentGCOptions{paused=false, estimationDisabled=true, gcSizeDeltaEstimation=1073741824, retryCount=5, forceTimeout=3600, retainedGenerations=2, gcType=TAIL}, current generation=GCGeneration{generation=1,fullGeneration=1,isCompacted=false}, new generation=GCGeneration{generation=2,fullGeneration=1,isCompacted=true}
11:19:16.891 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #2: estimated number of nodes to compact is 92946, based on 28731 nodes compacted to 29543424 bytes on disk in previous compaction and current size of 95574528 bytes on disk.
TarMK GC #2: estimated number of nodes to compact is 92946, based on 28731 nodes compacted to 29543424 bytes on disk in previous compaction and current size of 95574528 bytes on disk.
11:19:16.891 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #2: compacting root.
TarMK GC #2: compacting root.
11:19:17.821 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #2: compaction cycle 0 completed in 930.6 ms (930 ms). Compacted b332364e-9044-4102-aff0-62dc22b386db.000012a9 to 951c5ba1-e47f-4e90-a173-f69f0629fbd4.0000190f
TarMK GC #2: compaction cycle 0 completed in 930.9 ms (930 ms). Compacted b332364e-9044-4102-aff0-62dc22b386db.000012a9 to 951c5ba1-e47f-4e90-a173-f69f0629fbd4.0000190f
11:19:17.829 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #2: compaction succeeded in 938.8 ms (938 ms), after 0 cycles
TarMK GC #2: compaction succeeded in 939.1 ms (939 ms), after 0 cycles
11:19:17.856 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #2: cleanup started.
TarMK GC #2: cleanup started.
11:19:18.345 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #2: cleanup marking files for deletion: target/junit8157909954958580019/data00000a.tar
TarMK GC #2: cleanup marking files for deletion: target/junit8157909954958580019/data00000a.tar
11:19:18.346 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #2: cleanup completed in 490.1 ms (490 ms). Post cleanup size is 77.3 MB (77254656 bytes) and space reclaimed 26.0 MB (26048512 bytes).
TarMK GC #2: cleanup completed in 490.4 ms (490 ms). Post cleanup size is 77.3 MB (77254656 bytes) and space reclaimed 26.0 MB (26048512 bytes).
11:19:18.347 INFO [pool-1-thread-1] SegmentCompactionIT.java:349 Scheduling TAIL compaction after 2 minutes
11:19:20.920 INFO [TarMK filer reaper [target/junit8157909954958580019]] FileReaper.java:81 Removed files target/junit8157909954958580019/data00000a.tar
11:21:18.351 INFO [pool-1-thread-10] SegmentCompactionIT.java:742 Running compaction
11:21:18.351 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #3: started
TarMK GC #3: started
11:21:18.351 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #3: estimation skipped because it was explicitly disabled
TarMK GC #3: estimation skipped because it was explicitly disabled
11:21:18.352 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #3: setting up a listener to cancel compaction if available memory on pool 'PS Old Gen' drops below 429.5 MB (429549158 bytes) / 15%.
TarMK GC #3: setting up a listener to cancel compaction if available memory on pool 'PS Old Gen' drops below 429.5 MB (429549158 bytes) / 15%.
11:21:18.353 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #3: available memory level 2.6 GB (2614431808 bytes) is good, expecting at least 429.5 MB (429549158 bytes)
TarMK GC #3: available memory level 2.6 GB (2614431808 bytes) is good, expecting at least 429.5 MB (429549158 bytes)
11:21:18.353 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #3: running tail compaction
TarMK GC #3: running tail compaction
11:21:18.354 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #3: compaction started, gc options=SegmentGCOptions{paused=false, estimationDisabled=true, gcSizeDeltaEstimation=1073741824, retryCount=5, forceTimeout=3600, retainedGenerations=2, gcType=TAIL}, current generation=GCGeneration{generation=2,fullGeneration=1,isCompacted=false}, new generation=GCGeneration{generation=3,fullGeneration=1,isCompacted=true}
TarMK GC #3: compaction started, gc options=SegmentGCOptions{paused=false, estimationDisabled=true, gcSizeDeltaEstimation=1073741824, retryCount=5, forceTimeout=3600, retainedGenerations=2, gcType=TAIL}, current generation=GCGeneration{generation=2,fullGeneration=1,isCompacted=false}, new generation=GCGeneration{generation=3,fullGeneration=1,isCompacted=true}
11:21:18.354 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #3: estimated number of nodes to compact is 146575, based on 58425 nodes compacted to 77254656 bytes on disk in previous compaction and current size of 193814528 bytes on disk.
TarMK GC #3: estimated number of nodes to compact is 146575, based on 58425 nodes compacted to 77254656 bytes on disk in previous compaction and current size of 193814528 bytes on disk.
11:21:18.354 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #3: found checkpoint 6d691390-6cf3-4e61-b8f1-fa950e80deb8 created at Wed Jan 10 11:21:10 CET 2018.
TarMK GC #3: found checkpoint 6d691390-6cf3-4e61-b8f1-fa950e80deb8 created at Wed Jan 10 11:21:10 CET 2018.
11:21:18.354 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #3: found checkpoint ba28096b-9164-4e5b-ac03-1303f17d8edc created at Wed Jan 10 11:21:13 CET 2018.
TarMK GC #3: found checkpoint ba28096b-9164-4e5b-ac03-1303f17d8edc created at Wed Jan 10 11:21:13 CET 2018.
11:21:18.355 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #3: compacting checkpoints/6d691390-6cf3-4e61-b8f1-fa950e80deb8/root.
TarMK GC #3: compacting checkpoints/6d691390-6cf3-4e61-b8f1-fa950e80deb8/root.
11:21:19.191 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #3: compacting checkpoints/ba28096b-9164-4e5b-ac03-1303f17d8edc/root.
TarMK GC #3: compacting checkpoints/ba28096b-9164-4e5b-ac03-1303f17d8edc/root.
11:21:19.192 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #3: found checkpoints/ba28096b-9164-4e5b-ac03-1303f17d8edc/root in cache.
TarMK GC #3: found checkpoints/ba28096b-9164-4e5b-ac03-1303f17d8edc/root in cache.
11:21:19.192 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #3: compacting root.
TarMK GC #3: compacting root.
11:21:19.365 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #3: compaction cycle 0 completed in 1.011 s (1011 ms). Compacted 365f31f5-c0ba-48bc-afcc-ef5a62923f8e.0000097d to 3a1c5cc1-a415-438c-a8ae-0e16fd2d6f93.000000dd
TarMK GC #3: compaction cycle 0 completed in 1.012 s (1011 ms). Compacted 365f31f5-c0ba-48bc-afcc-ef5a62923f8e.0000097d to 3a1c5cc1-a415-438c-a8ae-0e16fd2d6f93.000000dd
11:21:19.374 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #3: compaction succeeded in 1.020 s (1020 ms), after 0 cycles
TarMK GC #3: compaction succeeded in 1.020 s (1020 ms), after 0 cycles
11:21:19.390 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #3: cleanup started.
TarMK GC #3: cleanup started.
11:21:20.014 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #3: cleanup marking files for deletion: target/junit8157909954958580019/data00001a.tar
TarMK GC #3: cleanup marking files for deletion: target/junit8157909954958580019/data00001a.tar
11:21:20.015 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #3: cleanup completed in 625.1 ms (625 ms). Post cleanup size is 140.0 MB (139978240 bytes) and space reclaimed 66.9 MB (66931200 bytes).
TarMK GC #3: cleanup completed in 625.3 ms (625 ms). Post cleanup size is 140.0 MB (139978240 bytes) and space reclaimed 66.9 MB (66931200 bytes).
11:21:20.016 INFO [pool-1-thread-10] SegmentCompactionIT.java:349 Scheduling TAIL compaction after 2 minutes
11:21:20.803 INFO [TarMK filer reaper [target/junit8157909954958580019]] FileReaper.java:81 Removed files target/junit8157909954958580019/data00001a.tar
11:23:20.017 INFO [pool-1-thread-42] SegmentCompactionIT.java:742 Running compaction
11:23:20.017 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #4: started
TarMK GC #4: started
11:23:20.018 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #4: estimation skipped because it was explicitly disabled
TarMK GC #4: estimation skipped because it was explicitly disabled
11:23:20.018 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #4: setting up a listener to cancel compaction if available memory on pool 'PS Old Gen' drops below 429.5 MB (429549158 bytes) / 15%.
TarMK GC #4: setting up a listener to cancel compaction if available memory on pool 'PS Old Gen' drops below 429.5 MB (429549158 bytes) / 15%.
11:23:20.018 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #4: available memory level 2.6 GB (2552091456 bytes) is good, expecting at least 429.5 MB (429549158 bytes)
TarMK GC #4: available memory level 2.6 GB (2552091456 bytes) is good, expecting at least 429.5 MB (429549158 bytes)
11:23:20.018 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #4: running tail compaction
TarMK GC #4: running tail compaction
11:23:20.018 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #4: compaction started, gc options=SegmentGCOptions{paused=false, estimationDisabled=true, gcSizeDeltaEstimation=1073741824, retryCount=5, forceTimeout=3600, retainedGenerations=2, gcType=TAIL}, current generation=GCGeneration{generation=3,fullGeneration=1,isCompacted=false}, new generation=GCGeneration{generation=4,fullGeneration=1,isCompacted=true}
TarMK GC #4: compaction started, gc options=SegmentGCOptions{paused=false, estimationDisabled=true, gcSizeDeltaEstimation=1073741824, retryCount=5, forceTimeout=3600, retainedGenerations=2, gcType=TAIL}, current generation=GCGeneration{generation=3,fullGeneration=1,isCompacted=false}, new generation=GCGeneration{generation=4,fullGeneration=1,isCompacted=true}
11:23:20.018 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #4: estimated number of nodes to compact is 186338, based on 96693 nodes compacted to 139978240 bytes on disk in previous compaction and current size of 269754368 bytes on disk.
TarMK GC #4: estimated number of nodes to compact is 186338, based on 96693 nodes compacted to 139978240 bytes on disk in previous compaction and current size of 269754368 bytes on disk.
11:23:20.019 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #4: found checkpoint 501dd358-a13f-42be-a04b-598c19f255cc created at Wed Jan 10 11:23:16 CET 2018.
TarMK GC #4: found checkpoint 501dd358-a13f-42be-a04b-598c19f255cc created at Wed Jan 10 11:23:16 CET 2018.
11:23:20.019 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #4: compacting checkpoints/501dd358-a13f-42be-a04b-598c19f255cc/root.
TarMK GC #4: compacting checkpoints/501dd358-a13f-42be-a04b-598c19f255cc/root.
11:23:21.396 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #4: compacting root.
TarMK GC #4: compacting root.
11:23:21.748 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #4: compaction cycle 0 completed in 1.730 s (1730 ms). Compacted d228dc7c-2707-43d5-a7af-0511caac88b4.00000004 to f7dd6de4-3b50-491d-adb3-b60498acebe6.0000013d
TarMK GC #4: compaction cycle 0 completed in 1.730 s (1730 ms). Compacted d228dc7c-2707-43d5-a7af-0511caac88b4.00000004 to f7dd6de4-3b50-491d-adb3-b60498acebe6.0000013d
11:23:21.749 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #4: compaction detected concurrent commits while compacting. Compacting these commits. Cycle 1 of 5
TarMK GC #4: compaction detected concurrent commits while compacting. Compacting these commits. Cycle 1 of 5
11:23:21.749 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #4: found checkpoint 501dd358-a13f-42be-a04b-598c19f255cc created at Wed Jan 10 11:23:16 CET 2018.
TarMK GC #4: found checkpoint 501dd358-a13f-42be-a04b-598c19f255cc created at Wed Jan 10 11:23:16 CET 2018.
11:23:21.749 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #4: compacting checkpoints/501dd358-a13f-42be-a04b-598c19f255cc/root.
TarMK GC #4: compacting checkpoints/501dd358-a13f-42be-a04b-598c19f255cc/root.
11:23:21.749 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #4: found checkpoints/501dd358-a13f-42be-a04b-598c19f255cc/root in cache.
TarMK GC #4: found checkpoints/501dd358-a13f-42be-a04b-598c19f255cc/root in cache.
11:23:21.749 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #4: compacting root.
TarMK GC #4: compacting root.
11:23:22.051 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #4: compaction cycle 1 completed in 302.2 ms (302 ms). Compacted aa5bafbc-27c3-4f4f-a1a6-c1583359c99a.00000129 against d228dc7c-2707-43d5-a7af-0511caac88b4.00000004 to b89d121c-31a9-465a-a9bf-c299f9a4d0e1.00000988
TarMK GC #4: compaction cycle 1 completed in 302.4 ms (302 ms). Compacted aa5bafbc-27c3-4f4f-a1a6-c1583359c99a.00000129 against d228dc7c-2707-43d5-a7af-0511caac88b4.00000004 to b89d121c-31a9-465a-a9bf-c299f9a4d0e1.00000988
11:23:22.061 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #4: compaction succeeded in 2.043 s (2042 ms), after 1 cycles
TarMK GC #4: compaction succeeded in 2.043 s (2043 ms), after 1 cycles
11:23:22.072 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #4: cleanup started.
TarMK GC #4: cleanup started.
11:23:22.588 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #4: cleanup marking files for deletion: target/junit8157909954958580019/data00002a.tar
TarMK GC #4: cleanup marking files for deletion: target/junit8157909954958580019/data00002a.tar
11:23:22.590 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #4: cleanup completed in 517.3 ms (517 ms). Post cleanup size is 175.5 MB (175464448 bytes) and space reclaimed 118.6 MB (118562304 bytes).
TarMK GC #4: cleanup completed in 517.5 ms (517 ms). Post cleanup size is 175.5 MB (175464448 bytes) and space reclaimed 118.6 MB (118562304 bytes).
11:23:22.590 INFO [pool-1-thread-42] SegmentCompactionIT.java:349 Scheduling FULL compaction after 2 minutes
11:23:25.809 INFO [TarMK filer reaper [target/junit8157909954958580019]] FileReaper.java:81 Removed files target/junit8157909954958580019/data00002a.tar
11:25:22.595 INFO [pool-1-thread-18] SegmentCompactionIT.java:742 Running compaction
11:25:22.595 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #5: started
TarMK GC #5: started
11:25:22.595 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #5: estimation skipped because it was explicitly disabled
TarMK GC #5: estimation skipped because it was explicitly disabled
11:25:22.596 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #5: setting up a listener to cancel compaction if available memory on pool 'PS Old Gen' drops below 429.5 MB (429549158 bytes) / 15%.
TarMK GC #5: setting up a listener to cancel compaction if available memory on pool 'PS Old Gen' drops below 429.5 MB (429549158 bytes) / 15%.
11:25:22.596 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #5: available memory level 2.5 GB (2527291136 bytes) is good, expecting at least 429.5 MB (429549158 bytes)
TarMK GC #5: available memory level 2.5 GB (2527291136 bytes) is good, expecting at least 429.5 MB (429549158 bytes)
11:25:22.596 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #5: running full compaction
TarMK GC #5: running full compaction
11:25:22.596 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #5: compaction started, gc options=SegmentGCOptions{paused=false, estimationDisabled=true, gcSizeDeltaEstimation=1073741824, retryCount=5, forceTimeout=3600, retainedGenerations=2, gcType=FULL}, current generation=GCGeneration{generation=4,fullGeneration=1,isCompacted=false}, new generation=GCGeneration{generation=5,fullGeneration=2,isCompacted=true}
TarMK GC #5: compaction started, gc options=SegmentGCOptions{paused=false, estimationDisabled=true, gcSizeDeltaEstimation=1073741824, retryCount=5, forceTimeout=3600, retainedGenerations=2, gcType=FULL}, current generation=GCGeneration{generation=4,fullGeneration=1,isCompacted=false}, new generation=GCGeneration{generation=5,fullGeneration=2,isCompacted=true}
11:25:22.596 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #5: estimated number of nodes to compact is 263986, based on 149429 nodes compacted to 175464448 bytes on disk in previous compaction and current size of 309981184 bytes on disk.
TarMK GC #5: estimated number of nodes to compact is 263986, based on 149429 nodes compacted to 175464448 bytes on disk in previous compaction and current size of 309981184 bytes on disk.
11:25:22.596 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #5: compacting root.
TarMK GC #5: compacting root.
11:25:23.681 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #5: compaction cycle 0 completed in 1.085 s (1085 ms). Compacted 581d397f-6199-48df-ab97-bd97f0774d19.00001143 to 4c8cae09-d27e-405e-a529-fc30acf16191.00000357
TarMK GC #5: compaction cycle 0 completed in 1.085 s (1085 ms). Compacted 581d397f-6199-48df-ab97-bd97f0774d19.00001143 to 4c8cae09-d27e-405e-a529-fc30acf16191.00000357
11:25:23.686 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #5: compaction succeeded in 1.090 s (1090 ms), after 0 cycles
TarMK GC #5: compaction succeeded in 1.090 s (1090 ms), after 0 cycles
11:25:23.707 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #5: cleanup started.
TarMK GC #5: cleanup started.
11:25:24.344 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #5: cleanup marking files for deletion: target/junit8157909954958580019/data00000b.tar,target/junit8157909954958580019/data00001b.tar,target/junit8157909954958580019/data00002b.tar,target/junit8157909954958580019/data00003a.tar
TarMK GC #5: cleanup marking files for deletion: target/junit8157909954958580019/data00000b.tar,target/junit8157909954958580019/data00001b.tar,target/junit8157909954958580019/data00002b.tar,target/junit8157909954958580019/data00003a.tar
11:25:24.345 INFO [TarMK revision gc [target/junit8157909954958580019]] LoggingGCMonitor.java:44 TarMK GC #5: cleanup completed in 638.7 ms (638 ms). Post cleanup size is 171.1 MB (171075072 bytes) and space reclaimed 158.4 MB (158447616 bytes).
TarMK GC #5: cleanup completed in 639.1 ms (639 ms). Post cleanup size is 171.1 MB (171075072 bytes) and space reclaimed 158.4 MB (158447616 bytes).
11:25:24.346 INFO [pool-1-thread-18] SegmentCompactionIT.java:349 Scheduling TAIL compaction after 2 minutes
11:25:24.394 ERROR [pool-1-thread-11] SegmentNotFoundExceptionListener.java:48 Segment not found: 2d5c49b0-14a1-47eb-aa63-7de12af547c5. SegmentId age=245470ms,segment-generation=GCGeneration{generation=3,fullGeneration=1,isCompacted=true}
org.apache.jackrabbit.oak.segment.SegmentNotFoundException: Segment 2d5c49b0-14a1-47eb-aa63-7de12af547c5 not found
at org.apache.jackrabbit.oak.segment.file.AbstractFileStore.readSegmentUncached(AbstractFileStore.java:276) ~[classes/:na]
at org.apache.jackrabbit.oak.segment.file.FileStore.lambda$readSegment$5(FileStore.java:477) ~[classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCache.lambda$getSegment$0(SegmentCache.java:116) ~[classes/:na]
at com.google.common.cache.LocalCache$LocalManualCache$1.load(LocalCache.java:4724) ~[guava-15.0.jar:na]
at com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3522) ~[guava-15.0.jar:na]
at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2315) ~[guava-15.0.jar:na]
at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2278) ~[guava-15.0.jar:na]
at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2193) ~[guava-15.0.jar:na]
at com.google.common.cache.LocalCache.get(LocalCache.java:3932) ~[guava-15.0.jar:na]
at com.google.common.cache.LocalCache$LocalManualCache.get(LocalCache.java:4721) ~[guava-15.0.jar:na]
at org.apache.jackrabbit.oak.segment.SegmentCache.getSegment(SegmentCache.java:113) ~[classes/:na]
at org.apache.jackrabbit.oak.segment.file.FileStore.readSegment(FileStore.java:477) ~[classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentId.getSegment(SegmentId.java:154) [classes/:na]
at org.apache.jackrabbit.oak.segment.Record.getSegment(Record.java:70) [classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentNodeState.getTemplateId(SegmentNodeState.java:101) [classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentNodeState.getTemplate(SegmentNodeState.java:110) [classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentNodeState.getChildNodeCount(SegmentNodeState.java:397) [classes/:na]
at org.apache.jackrabbit.oak.plugins.memory.MemoryNodeBuilder.getChildNodeCount(MemoryNodeBuilder.java:303) [classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCompactionIT$RandomWriter.randomStep(SegmentCompactionIT.java:577) [test-classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCompactionIT$RandomWriter.chooseRandomNode(SegmentCompactionIT.java:563) [test-classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCompactionIT$RandomWriter.chooseRandomNode(SegmentCompactionIT.java:569) [test-classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCompactionIT$RandomWriter.addRandomNode(SegmentCompactionIT.java:596) [test-classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCompactionIT$RandomWriter.modify(SegmentCompactionIT.java:552) [test-classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCompactionIT$RandomWriter.access$2200(SegmentCompactionIT.java:479) [test-classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCompactionIT$RandomWriter$1.call(SegmentCompactionIT.java:520) [test-classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCompactionIT$RandomWriter$1.call(SegmentCompactionIT.java:515) [test-classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCompactionIT$RandomWriter.run(SegmentCompactionIT.java:509) [test-classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCompactionIT$RandomWriter.call(SegmentCompactionIT.java:515) [test-classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCompactionIT$RandomWriter.call(SegmentCompactionIT.java:479) [test-classes/:na]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_121]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_121]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_121]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_121]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [na:1.8.0_121]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_121]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_121]
at java.lang.Thread.run(Thread.java:745) [na:1.8.0_121]
11:25:24.396 ERROR [pool-1-thread-11] SegmentCompactionIT.java:1166 Writer error
org.apache.jackrabbit.oak.segment.SegmentNotFoundException: Segment 2d5c49b0-14a1-47eb-aa63-7de12af547c5 not found
at org.apache.jackrabbit.oak.segment.file.AbstractFileStore.readSegmentUncached(AbstractFileStore.java:276) ~[classes/:na]
at org.apache.jackrabbit.oak.segment.file.FileStore.lambda$readSegment$5(FileStore.java:477) ~[classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCache.lambda$getSegment$0(SegmentCache.java:116) ~[classes/:na]
at com.google.common.cache.LocalCache$LocalManualCache$1.load(LocalCache.java:4724) ~[guava-15.0.jar:na]
at com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3522) ~[guava-15.0.jar:na]
at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2315) ~[guava-15.0.jar:na]
at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2278) ~[guava-15.0.jar:na]
at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2193) ~[guava-15.0.jar:na]
at com.google.common.cache.LocalCache.get(LocalCache.java:3932) ~[guava-15.0.jar:na]
at com.google.common.cache.LocalCache$LocalManualCache.get(LocalCache.java:4721) ~[guava-15.0.jar:na]
at org.apache.jackrabbit.oak.segment.SegmentCache.getSegment(SegmentCache.java:113) ~[classes/:na]
at org.apache.jackrabbit.oak.segment.file.FileStore.readSegment(FileStore.java:477) ~[classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentId.getSegment(SegmentId.java:154) ~[classes/:na]
at org.apache.jackrabbit.oak.segment.Record.getSegment(Record.java:70) ~[classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentNodeState.getTemplateId(SegmentNodeState.java:101) ~[classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentNodeState.getTemplate(SegmentNodeState.java:110) ~[classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentNodeState.getChildNodeCount(SegmentNodeState.java:397) ~[classes/:na]
at org.apache.jackrabbit.oak.plugins.memory.MemoryNodeBuilder.getChildNodeCount(MemoryNodeBuilder.java:303) ~[classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCompactionIT$RandomWriter.randomStep(SegmentCompactionIT.java:577) ~[test-classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCompactionIT$RandomWriter.chooseRandomNode(SegmentCompactionIT.java:563) ~[test-classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCompactionIT$RandomWriter.chooseRandomNode(SegmentCompactionIT.java:569) ~[test-classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCompactionIT$RandomWriter.addRandomNode(SegmentCompactionIT.java:596) ~[test-classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCompactionIT$RandomWriter.modify(SegmentCompactionIT.java:552) ~[test-classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCompactionIT$RandomWriter.access$2200(SegmentCompactionIT.java:479) ~[test-classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCompactionIT$RandomWriter$1.call(SegmentCompactionIT.java:520) ~[test-classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCompactionIT$RandomWriter$1.call(SegmentCompactionIT.java:515) ~[test-classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCompactionIT$RandomWriter.run(SegmentCompactionIT.java:509) ~[test-classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCompactionIT$RandomWriter.call(SegmentCompactionIT.java:515) ~[test-classes/:na]
at org.apache.jackrabbit.oak.segment.SegmentCompactionIT$RandomWriter.call(SegmentCompactionIT.java:479) ~[test-classes/:na]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_121]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_121]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_121]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_121]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [na:1.8.0_121]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_121]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_121]
at java.lang.Thread.run(Thread.java:745) [na:1.8.0_121]
{noformat}
> SNFE after full compaction
> --------------------------
>
> Key: OAK-7132
> URL: https://issues.apache.org/jira/browse/OAK-7132
> Project: Jackrabbit Oak
> Issue Type: Bug
> Components: segment-tar
> Affects Versions: 1.8.0
> Reporter: Michael Dürig
> Assignee: Michael Dürig
> Priority: Blocker
> Labels: compaction
> Fix For: 1.9.0, 1.10, 1.8.1
>
>
> In some cases we observed a {{SNFE}} right after a the cleanup following a full compaction:
> {noformat}
> 31.12.2017 04:25:19.816 *ERROR* [pool-17-thread-22] org.apache.jackrabbit.oak.segment.SegmentNotFoundExceptionListener Segment not found: a82a99a3-f1e9-49b7-a1e0-55e7fec80c41. SegmentId age=609487478ms,segment-generation=GCGeneration{generation=4,fullGeneration=2,isCompacted=true}
> org.apache.jackrabbit.oak.segment.SegmentNotFoundException: Segment a82a99a3-f1e9-49b7-a1e0-55e7fec80c41 not found
> at org.apache.jackrabbit.oak.segment.file.AbstractFileStore.readSegmentUncached(AbstractFileStore.java:276)
> at org.apache.jackrabbit.oak.segment.file.FileStore.lambda$readSegment$5(FileStore.java:478)
> at org.apache.jackrabbit.oak.segment.SegmentCache.lambda$getSegment$0(SegmentCache.java:116)
> at com.google.common.cache.LocalCache$LocalManualCache$1.load(LocalCache.java:4724)
> at com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3522)
> at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2315)
> at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2278)
> at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2193)
> at com.google.common.cache.LocalCache.get(LocalCache.java:3932)
> at com.google.common.cache.LocalCache$LocalManualCache.get(LocalCache.java:4721)
> at org.apache.jackrabbit.oak.segment.SegmentCache.getSegment(SegmentCache.java:113)
> at org.apache.jackrabbit.oak.segment.file.FileStore.readSegment(FileStore.java:478)
> at org.apache.jackrabbit.oak.segment.SegmentId.getSegment(SegmentId.java:154)
> at org.apache.jackrabbit.oak.segment.CachingSegmentReader$1.apply(CachingSegmentReader.java:94)
> at org.apache.jackrabbit.oak.segment.CachingSegmentReader$1.apply(CachingSegmentReader.java:90)
> at org.apache.jackrabbit.oak.segment.ReaderCache.get(ReaderCache.java:118)
> at org.apache.jackrabbit.oak.segment.CachingSegmentReader.readString(CachingSegmentReader.java:90)
> at org.apache.jackrabbit.oak.segment.MapRecord.getEntry(MapRecord.java:220)
> at org.apache.jackrabbit.oak.segment.MapRecord.getEntry(MapRecord.java:173)
> at org.apache.jackrabbit.oak.segment.SegmentNodeState.getChildNode(SegmentNodeState.java:423)
> at org.apache.jackrabbit.oak.plugins.memory.MemoryNodeBuilder.<init>(MemoryNodeBuilder.java:143)
> at org.apache.jackrabbit.oak.segment.SegmentNodeBuilder.<init>(SegmentNodeBuilder.java:93)
> at org.apache.jackrabbit.oak.segment.SegmentNodeBuilder.createChildBuilder(SegmentNodeBuilder.java:148)
> at org.apache.jackrabbit.oak.plugins.memory.MemoryNodeBuilder.getChildNode(MemoryNodeBuilder.java:331)
> at org.apache.jackrabbit.oak.core.SecureNodeBuilder.<init>(SecureNodeBuilder.java:112)
> at org.apache.jackrabbit.oak.core.SecureNodeBuilder.getChildNode(SecureNodeBuilder.java:329)
> at org.apache.jackrabbit.oak.core.MutableTree.getTree(MutableTree.java:290)
> at org.apache.jackrabbit.oak.core.MutableRoot.getTree(MutableRoot.java:220)
> at org.apache.jackrabbit.oak.core.MutableRoot.getTree(MutableRoot.java:69)
> at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.getItem(SessionDelegate.java:442)
> at org.apache.jackrabbit.oak.jcr.session.SessionImpl.getItemInternal(SessionImpl.java:167)
> at org.apache.jackrabbit.oak.jcr.session.SessionImpl.access$400(SessionImpl.java:82)
> at org.apache.jackrabbit.oak.jcr.session.SessionImpl$3.performNullable(SessionImpl.java:229)
> at org.apache.jackrabbit.oak.jcr.session.SessionImpl$3.performNullable(SessionImpl.java:226)
> at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.performNullable(SessionDelegate.java:243)
> at org.apache.jackrabbit.oak.jcr.session.SessionImpl.getItemOrNull(SessionImpl.java:226)
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)