[
https://issues.apache.org/jira/browse/JCRVLT-730?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17785824#comment-17785824
]
Konrad Windszus edited comment on JCRVLT-730 at 11/14/23 3:13 PM:
------------------------------------------------------------------
Debug log exposes the following when the test is failing:
{code}
14:51:02.430 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Starting sync cycle for
SyncSpec{fileRoot=/tmp/junit13097876300643150377/junit11032106733571259963}.
14:51:02.446 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Scanning filesystem for changes
SyncSpec{fileRoot=/tmp/junit13097876300643150377/junit11032106733571259963}
14:51:02.446 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
onDirectoryCreate(/tmp/junit13097876300643150377/junit11032106733571259963/testroot),
accepted=true
14:51:02.446 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
onFileCreate(/tmp/junit13097876300643150377/junit11032106733571259963/testroot/testfile.txt),
accepted=true
14:51:02.446 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
onFileChange(/tmp/junit13097876300643150377/junit11032106733571259963/.vlt-sync-filter.xml),
accepted=false
14:51:02.446 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler - ****
about sync
file://tmp/junit13097876300643150377/junit11032106733571259963/testroot ->
jcr:///testroot
14:51:02.446 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler - ****
rejected. filter does not include /testroot
14:51:02.446 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler - ****
about sync
file://tmp/junit13097876300643150377/junit11032106733571259963/testroot/testfile.txt
-> jcr:///testroot/testfile.txt
14:51:02.446 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler - ****
rejected. filter does not include /testroot/testfile.txt
14:51:02.447 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler - Sync
cycle completed for
SyncSpec{fileRoot=/tmp/junit13097876300643150377/junit11032106733571259963}
{code}
was (Author: kwin):
Debug log exposes the following when the test is failing:
{code}
09:06:35.782 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Starting sync cycle for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}.
09:06:35.782 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Scanning filesystem for changes
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
09:06:35.783 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler - Sync
cycle completed for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
[INFO] Tests run: 96, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 25.70 s
-- in org.apache.jackrabbit.vault.packaging.integration.SubPackagesIT
09:06:36.034 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Starting sync cycle for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}.
09:06:36.034 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Scanning filesystem for changes
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
09:06:36.036 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler - Sync
cycle completed for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
09:06:36.287 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Starting sync cycle for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}.
09:06:36.287 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Scanning filesystem for changes
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
09:06:36.289 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler - Sync
cycle completed for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
09:06:36.540 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Starting sync cycle for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}.
09:06:36.540 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Scanning filesystem for changes
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
09:06:36.542 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler - Sync
cycle completed for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
09:06:36.792 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Starting sync cycle for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}.
09:06:36.793 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Scanning filesystem for changes
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
09:06:36.795 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler - Sync
cycle completed for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
09:06:37.045 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Starting sync cycle for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}.
09:06:37.045 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Scanning filesystem for changes
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
09:06:37.048 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler - Sync
cycle completed for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
09:06:37.299 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Starting sync cycle for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}.
09:06:37.299 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Scanning filesystem for changes
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
09:06:37.301 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler - Sync
cycle completed for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
09:06:37.552 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Starting sync cycle for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}.
09:06:37.552 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Scanning filesystem for changes
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
09:06:37.553 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler - Sync
cycle completed for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
09:06:37.804 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Starting sync cycle for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}.
09:06:37.804 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Scanning filesystem for changes
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
09:06:37.806 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler - Sync
cycle completed for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
09:06:38.056 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Starting sync cycle for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}.
09:06:38.056 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Scanning filesystem for changes
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
09:06:38.059 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler - Sync
cycle completed for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
09:06:38.309 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Starting sync cycle for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}.
09:06:38.309 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Scanning filesystem for changes
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
09:06:38.311 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler - Sync
cycle completed for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
09:06:38.381 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Starting sync cycle for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}.
09:06:38.381 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler - ****
about sync jcr://testroot/testfile ->
file:///tmp/junit14823511034048835553/junit4530291883935561564/testroot/testfile
09:06:38.385 [Vault Sync Thread] INFO o.a.j.vault.sync.impl.SyncLog - U
file:///tmp/junit14823511034048835553/junit4530291883935561564/testroot/testfile
09:06:38.385 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
Scanning filesystem for changes
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
09:06:38.386 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
onFileChange(/tmp/junit14823511034048835553/junit4530291883935561564/.vlt-sync.log),
accepted=false
09:06:38.386 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
onFileChange(/tmp/junit14823511034048835553/junit4530291883935561564/testroot/testfile),
accepted=true
09:06:38.386 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler -
ignoring change triggered by previous JCR->FS update.
/tmp/junit14823511034048835553/junit4530291883935561564/testroot/testfile
09:06:38.387 [Vault Sync Thread] INFO o.a.j.vault.sync.impl.SyncResult -
SyncResult:
fs=/tmp/junit14823511034048835553/junit4530291883935561564/testroot/testfile
jcr=/testroot/testfile ops=UPDATE_FS
09:06:38.387 [Vault Sync Thread] DEBUG o.a.j.vault.sync.impl.SyncHandler - Sync
cycle completed for
SyncSpec{fileRoot=/tmp/junit14823511034048835553/junit4530291883935561564}
{code}
> Unstable IT: VaultSyncServiceImplIT.testAddRemoveFileFromNonVltCheckoutFolder
> -----------------------------------------------------------------------------
>
> Key: JCRVLT-730
> URL: https://issues.apache.org/jira/browse/JCRVLT-730
> Project: Jackrabbit FileVault
> Issue Type: Bug
> Reporter: Konrad Windszus
> Assignee: Konrad Windszus
> Priority: Major
> Fix For: 3.7.4
>
>
> {code}
> 16:52:18.914 [Vault Sync Thread] INFO o.a.j.vault.sync.impl.SyncHandler -
> Sync Once requested: JCR2FS
> 16:52:18.924 [Vault Sync Thread] INFO o.a.j.vault.sync.impl.SyncLog - A
> file:///tmp/junit6534468439393939733/junit3629697623599693036/testroot/
> 16:52:18.926 [Vault Sync Thread] INFO o.a.j.vault.sync.impl.SyncLog - A
> file:///tmp/junit6534468439393939733/junit3629697623599693036/testroot/testfile
> 16:52:18.927 [Vault Sync Thread] INFO o.a.j.vault.sync.impl.SyncResult -
> SyncResult:
> fs=/tmp/junit6534468439393939733/junit3629697623599693036/testroot
> jcr=/testroot ops=UPDATE_FS
> 16:52:18.927 [Vault Sync Thread] INFO o.a.j.vault.sync.impl.SyncResult -
> SyncResult:
> fs=/tmp/junit6534468439393939733/junit3629697623599693036/testroot/testfile
> jcr=/testroot/testfile ops=UPDATE_FS
> 16:52:24.068 [Vault Sync Thread] INFO o.a.j.vault.sync.impl.SyncLog - U
> file:///tmp/junit6534468439393939733/junit3629697623599693036/testroot/testfile
> 16:52:24.069 [Vault Sync Thread] INFO o.a.j.vault.sync.impl.SyncResult -
> SyncResult:
> fs=/tmp/junit6534468439393939733/junit3629697623599693036/testroot/testfile
> jcr=/testroot/testfile ops=UPDATE_FS
> [ERROR] Tests run: 2, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 26.54
> s <<< FAILURE! -- in
> org.apache.jackrabbit.vault.sync.impl.VaultSyncServiceImplIT
> [ERROR]
> org.apache.jackrabbit.vault.sync.impl.VaultSyncServiceImplIT.testAddRemoveFileFromNonVltCheckoutFolder
> -- Time elapsed: 20.87 s <<< ERROR!
> org.awaitility.core.ConditionTimeoutException: Condition with lambda
> expression in org.apache.jackrabbit.vault.sync.impl.VaultSyncServiceImplIT
> was not fulfilled within 20 seconds.
> at org.awaitility.core.ConditionAwaiter.await(ConditionAwaiter.java:167)
> at
> org.awaitility.core.CallableCondition.await(CallableCondition.java:78)
> at
> org.awaitility.core.CallableCondition.await(CallableCondition.java:26)
> at org.awaitility.core.ConditionFactory.until(ConditionFactory.java:985)
> at org.awaitility.core.ConditionFactory.until(ConditionFactory.java:954)
> at
> org.apache.jackrabbit.vault.sync.impl.VaultSyncServiceImplIT.testAddRemoveFileFromNonVltCheckoutFolder(VaultSyncServiceImplIT.java:75)
> {code}
> This happens on the Jenkins Ubuntu node with JDK 11 but it seems to be some
> kind of race condition.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
