[ 
https://issues.apache.org/jira/browse/JCRVLT-730?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17785824#comment-17785824
 ] 

Konrad Windszus commented on JCRVLT-730:
----------------------------------------

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)

Reply via email to