Class org.syncany.tests.integration.scenarios.ManyRenamesScenarioTest

1

tests

0

failures

0

ignored

0.851s

duration

100%

successful

Tests

Test Duration Result
testManyRenames 0.851s passed

Standard error

29-3-20 17:53:28.355 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.355 | LocalTransferMa | Test worker    | INFO : testTargetExists: Target exists.
29-3-20 17:53:28.363 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.363 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-A' ...
29-3-20 17:53:28.363 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.363 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.363 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.363 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.363 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.363 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.363 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.363 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.363 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.363 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-A' ...
29-3-20 17:53:28.363 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.363 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.363 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:28.363 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:28.363 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.363 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.363 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.363 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.363 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.363 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.363 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:28.363 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:28.374 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
29-3-20 17:53:28.374 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
29-3-20 17:53:28.379 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
29-3-20 17:53:28.381 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
29-3-20 17:53:28.382 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
29-3-20 17:53:28.385 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
29-3-20 17:53:28.385 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
29-3-20 17:53:28.385 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
29-3-20 17:53:28.385 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS databaseversion ( id int NOT NULL IDENTITY, status varchar(45) NOT NULL, localtime datetime NOT NULL, client varchar(45) NOT NULL, vectorclock_serialized varchar(1024) NOT NULL, UNIQUE (vectorclock_serialized) ); 
29-3-20 17:53:28.387 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  chunk ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.388 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  databaseversion_vectorclock ( databaseversion_id int NOT NULL, client varchar(45) NOT NULL, logicaltime int NOT NULL, PRIMARY KEY (databaseversion_id, client), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.390 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.391 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent_chunk ( filecontent_checksum varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, num int NOT NULL, PRIMARY KEY (filecontent_checksum, chunk_checksum, num), FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.393 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filehistory ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, PRIMARY KEY (id, databaseversion_id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.395 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  fileversion ( filehistory_id varchar(40) NOT NULL, version int NOT NULL, databaseversion_id int NOT NULL, path varchar(1024) NOT NULL, type varchar(45) NOT NULL, status varchar(45) NOT NULL, size bigint NOT NULL, lastmodified datetime NOT NULL, linktarget varchar(1024), filecontent_checksum varchar(40) DEFAULT NULL, updated datetime NOT NULL, posixperms varchar(45) DEFAULT NULL, dosattrs varchar(45) DEFAULT NULL, PRIMARY KEY (filehistory_id, version, databaseversion_id), FOREIGN KEY (filehistory_id, databaseversion_id) REFERENCES filehistory (id, databaseversion_id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.396 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.398 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_chunk ( multichunk_id varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, PRIMARY KEY (multichunk_id, chunk_checksum), FOREIGN KEY (multichunk_id) REFERENCES multichunk (id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.399 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_muddy ( id varchar(40) NOT NULL, machine_name varchar(255) NOT NULL, machine_version int NOT NULL, PRIMARY KEY (id) ); 
29-3-20 17:53:28.401 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  known_databases ( id int NOT NULL IDENTITY, client varchar(45) NOT NULL, filenumber int NOT NULL, UNIQUE (client, filenumber) ); 
29-3-20 17:53:28.402 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  general_settings ( key varchar(255) NOT NULL, value varchar(255) NOT NULL, PRIMARY KEY (key) ); 
29-3-20 17:53:28.403 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
29-3-20 17:53:28.403 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
29-3-20 17:53:28.404 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
29-3-20 17:53:28.406 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
29-3-20 17:53:28.408 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
29-3-20 17:53:28.409 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
29-3-20 17:53:28.410 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
29-3-20 17:53:28.411 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
29-3-20 17:53:28.416 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
29-3-20 17:53:28.416 | SqlRunner       | Test worker    | INFO : SQL:    CREATE VIEW databaseversion_master AS SELECT dbv.*, vc.logicaltime as client_version FROM databaseversion dbv JOIN databaseversion_vectorclock vc on dbv.id=vc.databaseversion_id and dbv.client=vc.client WHERE dbv.status='MASTER'; 
29-3-20 17:53:28.418 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master AS SELECT fv0.* FROM fileversion fv0 JOIN databaseversion dbv ON fv0.databaseversion_id=dbv.id AND dbv.status='MASTER'; 
29-3-20 17:53:28.419 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_maxversion AS SELECT DISTINCT filehistory_id, MAX(version) version FROM fileversion_master GROUP BY filehistory_id; 
29-3-20 17:53:28.421 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_last AS SELECT fv.* FROM fileversion_master_maxversion fvmax JOIN fileversion_master fv ON fvmax.filehistory_id=fv.filehistory_id AND fvmax.version=fv.version WHERE fv.status<>'DELETED'; 
29-3-20 17:53:28.422 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
29-3-20 17:53:28.423 | SqlRunner       | Test worker    | INFO : SQL:    create view filehistory_full as select dbv.status as databaseversion_status, dbv.localtime as databaseversion_localtime, dbv.client as databaseversion_client, dbv.vectorclock_serialized as databaseversion_vectorclock_serialized, fh.* from databaseversion dbv join filehistory fh on dbv.id=fh.databaseversion_id; 
29-3-20 17:53:28.424 | SqlRunner       | Test worker    | INFO : SQL:  create view fileversion_full as select fhf.databaseversion_status, fhf.databaseversion_localtime, fhf.databaseversion_client, fhf.databaseversion_vectorclock_serialized, fv.* from filehistory_full fhf join fileversion fv on fhf.id=fv.filehistory_id and fhf.databaseversion_id=fv.databaseversion_id; 
29-3-20 17:53:28.425 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
29-3-20 17:53:28.425 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
29-3-20 17:53:28.425 | SqlRunner       | Test worker    | INFO : SQL:     create function substr_count(haystack varchar(255), needle varchar(255)) returns integer begin atomic declare strCount integer; declare lastIndex integer;  set strCount = 0; set lastIndex = 1;  while lastIndex <> 0 do set lastIndex = locate(needle, haystack, lastIndex);  if lastIndex <> 0 then set strCount = strCount + 1; set lastIndex = lastIndex + length(needle); end if; end while;  return strCount; end; 
29-3-20 17:53:28.427 | UpOperation     | Test worker    | INFO : 
29-3-20 17:53:28.427 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
29-3-20 17:53:28.427 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.427 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@8e182d9) ...
29-3-20 17:53:28.427 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.427 | StatusOperation | Test worker    | INFO : 
29-3-20 17:53:28.428 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-3-20 17:53:28.428 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.428 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:53:28.428 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@3673123a) ...
29-3-20 17:53:28.428 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-91297-client-A ...
29-3-20 17:53:28.428 | StatusOperation | Test worker    | FINE : - New file: A-original
29-3-20 17:53:28.428 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:53:28.428 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@413ea638) ...
29-3-20 17:53:28.428 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:28.429 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.429 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:28.429 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:53:28.429 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.429 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@3206f959) ...
29-3-20 17:53:28.429 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:28.429 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@5119143d) ...
29-3-20 17:53:28.429 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-3-20 17:53:28.429 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1585504408363] ...
29-3-20 17:53:28.429 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1585504408363]
29-3-20 17:53:28.429 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1585504408363] ...
29-3-20 17:53:28.430 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.430 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-3-20 17:53:28.430 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-3-20 17:53:28.430 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@4219ff78) ...
29-3-20 17:53:28.430 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-3-20 17:53:28.430 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-200329175039872-91297-client-A/A-original
29-3-20 17:53:28.430 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-200329175039872-91297-client-A/A-original
29-3-20 17:53:28.431 | Indexer         | AsyncI/syncany | FINE : - Chunk new: 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4
29-3-20 17:53:28.431 | Indexer         | AsyncI/syncany | FINE : - +MultiChunk e5a1677bb118567b7d75f70716390e5f0d025225
29-3-20 17:53:28.432 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4 > e5a1677bb118567b7d75f70716390e5f0d025225
29-3-20 17:53:28.432 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4 > /tmp/syncanytest/syncany-200329175039872-91297-client-A/A-original
29-3-20 17:53:28.432 | Indexer         | AsyncI/syncany | FINE : - /File: A-original (checksum 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4)
29-3-20 17:53:28.433 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: A-original, checksum: 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4)
29-3-20 17:53:28.433 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file A-original
29-3-20 17:53:28.433 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.433 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
29-3-20 17:53:28.433 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@25f0e799) ...
29-3-20 17:53:28.433 | Indexer         | AsyncI/syncany | FINE : - /MultiChunk e5a1677bb118567b7d75f70716390e5f0d025225
29-3-20 17:53:28.433 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@6e32d53c) ...
29-3-20 17:53:28.433 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504408430, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-3-20 17:53:28.433 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@4708151) ...
29-3-20 17:53:28.435 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-3-20 17:53:28.435 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-3-20 17:53:28.435 | UpOperation     | Test worker    | INFO : Last vector clock was: ()
29-3-20 17:53:28.436 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-3-20 17:53:28.436 | UpOperation     | Test worker    | INFO : - Uploading multichunk e5a1677bb118567b7d75f70716390e5f0d025225 from /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/multichunk-e5a1677bb118567b7d75f70716390e5f0d025225 to RemoteFile[name=multichunk-e5a1677bb118567b7d75f70716390e5f0d025225] ...
29-3-20 17:53:28.436 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/multichunk-e5a1677bb118567b7d75f70716390e5f0d025225 -> Temp. remote file: RemoteFile[name=temp-dOLgt-multichunk-e5a1677bb118567b7d75f70716390e5f0d025225], final location: RemoteFile[name=multichunk-e5a1677bb118567b7d75f70716390e5f0d025225]
29-3-20 17:53:28.436 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A1)/T=1585504408436, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-3-20 17:53:28.436 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A1)/T=1585504408436 to file /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-A-0000000001 ... 
29-3-20 17:53:28.436 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-A-0000000001 ...
29-3-20 17:53:28.436 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-3-20 17:53:28.437 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-A-0000000001 to RemoteFile[name=database-A-0000000001] ...
29-3-20 17:53:28.437 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-A-0000000001 -> Temp. remote file: RemoteFile[name=temp-uubRZ-database-A-0000000001], final location: RemoteFile[name=database-A-0000000001]
29-3-20 17:53:28.437 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-3-20 17:53:28.437 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-3-20 17:53:28.440 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/temp-transaction-6659875442702930773.tmp
29-3-20 17:53:28.440 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@1d28c1da) ...
29-3-20 17:53:28.440 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-2e8b30bd] ...
29-3-20 17:53:28.440 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-3-20 17:53:28.441 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@6c3a3fcc) ...
29-3-20 17:53:28.441 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/multichunk-e5a1677bb118567b7d75f70716390e5f0d025225 to temp. file RemoteFile[name=temp-dOLgt-multichunk-e5a1677bb118567b7d75f70716390e5f0d025225] ...
29-3-20 17:53:28.441 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@27c48e8) ...
29-3-20 17:53:28.441 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-A-0000000001 to temp. file RemoteFile[name=temp-uubRZ-database-A-0000000001] ...
29-3-20 17:53:28.442 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-dOLgt-multichunk-e5a1677bb118567b7d75f70716390e5f0d025225] to final location RemoteFile[name=multichunk-e5a1677bb118567b7d75f70716390e5f0d025225] ...
29-3-20 17:53:28.442 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-uubRZ-database-A-0000000001] to final location RemoteFile[name=database-A-0000000001] ...
29-3-20 17:53:28.442 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-2e8b30bd] ...
29-3-20 17:53:28.442 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-3-20 17:53:28.442 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-3-20 17:53:28.442 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A1)/T=1585504408436) ...
29-3-20 17:53:28.444 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-3-20 17:53:28.447 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A1)/T=1585504408436, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-3-20 17:53:28.447 | UpOperation     | Test worker    | INFO : Committing local database.
29-3-20 17:53:28.447 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-3-20 17:53:28.447 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504408435, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-3-20 17:53:28.448 | UpOperation     | Test worker    | INFO : Sync up done.
29-3-20 17:53:28.449 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1585504408363] ...
29-3-20 17:53:28.449 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1585504408363]
29-3-20 17:53:28.449 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:28.449 | Cache           | Test worker    | INFO : Cache size okay (51 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:28.449 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@738a2301) ...
29-3-20 17:53:28.449 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.449 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-B' ...
29-3-20 17:53:28.449 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.449 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.449 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.449 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.450 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.450 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.450 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.450 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.450 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.450 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-B' ...
29-3-20 17:53:28.450 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.450 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.450 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:28.450 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:28.450 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.450 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.450 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.450 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.450 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.450 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.450 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:28.450 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:28.469 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
29-3-20 17:53:28.470 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
29-3-20 17:53:28.475 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
29-3-20 17:53:28.477 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
29-3-20 17:53:28.478 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
29-3-20 17:53:28.481 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
29-3-20 17:53:28.481 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
29-3-20 17:53:28.482 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
29-3-20 17:53:28.482 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS databaseversion ( id int NOT NULL IDENTITY, status varchar(45) NOT NULL, localtime datetime NOT NULL, client varchar(45) NOT NULL, vectorclock_serialized varchar(1024) NOT NULL, UNIQUE (vectorclock_serialized) ); 
29-3-20 17:53:28.483 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  chunk ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.485 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  databaseversion_vectorclock ( databaseversion_id int NOT NULL, client varchar(45) NOT NULL, logicaltime int NOT NULL, PRIMARY KEY (databaseversion_id, client), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.486 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.488 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent_chunk ( filecontent_checksum varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, num int NOT NULL, PRIMARY KEY (filecontent_checksum, chunk_checksum, num), FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.489 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filehistory ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, PRIMARY KEY (id, databaseversion_id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.491 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  fileversion ( filehistory_id varchar(40) NOT NULL, version int NOT NULL, databaseversion_id int NOT NULL, path varchar(1024) NOT NULL, type varchar(45) NOT NULL, status varchar(45) NOT NULL, size bigint NOT NULL, lastmodified datetime NOT NULL, linktarget varchar(1024), filecontent_checksum varchar(40) DEFAULT NULL, updated datetime NOT NULL, posixperms varchar(45) DEFAULT NULL, dosattrs varchar(45) DEFAULT NULL, PRIMARY KEY (filehistory_id, version, databaseversion_id), FOREIGN KEY (filehistory_id, databaseversion_id) REFERENCES filehistory (id, databaseversion_id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.492 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.494 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_chunk ( multichunk_id varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, PRIMARY KEY (multichunk_id, chunk_checksum), FOREIGN KEY (multichunk_id) REFERENCES multichunk (id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:28.495 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_muddy ( id varchar(40) NOT NULL, machine_name varchar(255) NOT NULL, machine_version int NOT NULL, PRIMARY KEY (id) ); 
29-3-20 17:53:28.497 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  known_databases ( id int NOT NULL IDENTITY, client varchar(45) NOT NULL, filenumber int NOT NULL, UNIQUE (client, filenumber) ); 
29-3-20 17:53:28.498 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  general_settings ( key varchar(255) NOT NULL, value varchar(255) NOT NULL, PRIMARY KEY (key) ); 
29-3-20 17:53:28.499 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
29-3-20 17:53:28.499 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
29-3-20 17:53:28.500 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
29-3-20 17:53:28.502 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
29-3-20 17:53:28.503 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
29-3-20 17:53:28.504 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
29-3-20 17:53:28.506 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
29-3-20 17:53:28.507 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
29-3-20 17:53:28.508 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
29-3-20 17:53:28.508 | SqlRunner       | Test worker    | INFO : SQL:    CREATE VIEW databaseversion_master AS SELECT dbv.*, vc.logicaltime as client_version FROM databaseversion dbv JOIN databaseversion_vectorclock vc on dbv.id=vc.databaseversion_id and dbv.client=vc.client WHERE dbv.status='MASTER'; 
29-3-20 17:53:28.510 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master AS SELECT fv0.* FROM fileversion fv0 JOIN databaseversion dbv ON fv0.databaseversion_id=dbv.id AND dbv.status='MASTER'; 
29-3-20 17:53:28.512 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_maxversion AS SELECT DISTINCT filehistory_id, MAX(version) version FROM fileversion_master GROUP BY filehistory_id; 
29-3-20 17:53:28.514 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_last AS SELECT fv.* FROM fileversion_master_maxversion fvmax JOIN fileversion_master fv ON fvmax.filehistory_id=fv.filehistory_id AND fvmax.version=fv.version WHERE fv.status<>'DELETED'; 
29-3-20 17:53:28.515 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
29-3-20 17:53:28.516 | SqlRunner       | Test worker    | INFO : SQL:    create view filehistory_full as select dbv.status as databaseversion_status, dbv.localtime as databaseversion_localtime, dbv.client as databaseversion_client, dbv.vectorclock_serialized as databaseversion_vectorclock_serialized, fh.* from databaseversion dbv join filehistory fh on dbv.id=fh.databaseversion_id; 
29-3-20 17:53:28.517 | SqlRunner       | Test worker    | INFO : SQL:  create view fileversion_full as select fhf.databaseversion_status, fhf.databaseversion_localtime, fhf.databaseversion_client, fhf.databaseversion_vectorclock_serialized, fv.* from filehistory_full fhf join fileversion fv on fhf.id=fv.filehistory_id and fhf.databaseversion_id=fv.databaseversion_id; 
29-3-20 17:53:28.519 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
29-3-20 17:53:28.519 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
29-3-20 17:53:28.519 | SqlRunner       | Test worker    | INFO : SQL:     create function substr_count(haystack varchar(255), needle varchar(255)) returns integer begin atomic declare strCount integer; declare lastIndex integer;  set strCount = 0; set lastIndex = 1;  while lastIndex <> 0 do set lastIndex = locate(needle, haystack, lastIndex);  if lastIndex <> 0 then set strCount = strCount + 1; set lastIndex = lastIndex + length(needle); end if; end while;  return strCount; end; 
29-3-20 17:53:28.522 | DownOperation   | Test worker    | INFO : 
29-3-20 17:53:28.522 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
29-3-20 17:53:28.522 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.522 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@67c29be4) ...
29-3-20 17:53:28.522 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:28.523 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.523 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:28.523 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
29-3-20 17:53:28.523 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.523 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@2921da2a) ...
29-3-20 17:53:28.523 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:28.523 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
29-3-20 17:53:28.523 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@5fe455bf) ...
29-3-20 17:53:28.523 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@69465c6b) ...
29-3-20 17:53:28.523 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1585504408450] ...
29-3-20 17:53:28.523 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1585504408450]
29-3-20 17:53:28.524 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1585504408450] ...
29-3-20 17:53:28.524 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
29-3-20 17:53:28.524 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000001 to local cache at /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/database-A-0000000001
29-3-20 17:53:28.524 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@48670786) ...
29-3-20 17:53:28.525 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
29-3-20 17:53:28.525 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/database-A-0000000001 ...
29-3-20 17:53:28.526 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1585504408436
29-3-20 17:53:28.526 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-91297-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:28.526 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
29-3-20 17:53:28.527 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1585504408436], B=[]}
29-3-20 17:53:28.527 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
29-3-20 17:53:28.527 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1585504408436
29-3-20 17:53:28.527 | DatabaseReconci | Test worker    | INFO : - Winner is A with branch: 
29-3-20 17:53:28.527 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1585504408436
29-3-20 17:53:28.527 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
29-3-20 17:53:28.527 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
29-3-20 17:53:28.527 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
29-3-20 17:53:28.527 | DatabaseReconci | Test worker    | INFO : Losers Branch: []
29-3-20 17:53:28.527 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1585504408436]
29-3-20 17:53:28.527 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
29-3-20 17:53:28.527 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A1)/T=1585504408436]
29-3-20 17:53:28.527 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
29-3-20 17:53:28.527 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/database-A-0000000001 ...
29-3-20 17:53:28.528 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1585504408436
29-3-20 17:53:28.529 | DownOperation   | Test worker    | INFO : Determine file system actions ...
29-3-20 17:53:28.529 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.530 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
29-3-20 17:53:28.530 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
29-3-20 17:53:28.530 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
29-3-20 17:53:28.530 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.530 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file A-original
29-3-20 17:53:28.530 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-200329175039872-91297-client-B/A-original
29-3-20 17:53:28.530 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:28.531 | DownOperation   | Test worker    | INFO :   + Adding multichunk e5a1677bb118567b7d75f70716390e5f0d025225 to download list ...
29-3-20 17:53:28.531 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
29-3-20 17:53:28.531 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@5c2fd50d) ...
29-3-20 17:53:28.531 | Downloader      | Test worker    | INFO :   + Downloading multichunk e5a1677bb118567b7d75f70716390e5f0d025225 ...
29-3-20 17:53:28.532 | Downloader      | Test worker    | INFO :   + Decrypting multichunk e5a1677bb118567b7d75f70716390e5f0d025225 ...
29-3-20 17:53:28.532 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk e5a1677bb118567b7d75f70716390e5f0d025225 ...
29-3-20 17:53:28.532 | FileSystemActio | Test worker    | INFO :    Sorted actions:
29-3-20 17:53:28.532 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:28.532 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
29-3-20 17:53:28.532 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:28.533 | Assembler       | Test worker    | INFO :      - Creating file A-original to /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/temp-reconstructedFileVersion-16784222613267103033.tmp ...
29-3-20 17:53:28.534 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
29-3-20 17:53:28.534 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
29-3-20 17:53:28.534 | DownOperation   | Test worker    | INFO :   + Applying database version (A1)
29-3-20 17:53:28.534 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A1)/T=1585504408436, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-3-20 17:53:28.538 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1585504408450] ...
29-3-20 17:53:28.539 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1585504408450]
29-3-20 17:53:28.539 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:28.539 | Cache           | Test worker    | INFO : Cache size okay (51 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:28.539 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@45300b6) ...
29-3-20 17:53:28.539 | DownOperation   | Test worker    | INFO : Sync down done.
29-3-20 17:53:28.543 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-200329175039872-91297-client-A/A-original, but actual PATH = tmp/syncanytest/syncany-200329175039872-91297-client-B/A-original, for file tmp/syncanytest/syncany-200329175039872-91297-client-B/A-original
29-3-20 17:53:28.543 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.544 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.561 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from chunk order by CHECKSUM asc
29-3-20 17:53:28.561 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select STATUS, LOCALTIME, CLIENT, VECTORCLOCK_SERIALIZED from databaseversion order by ID asc
29-3-20 17:53:28.562 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CLIENT, LOGICALTIME from databaseversion_vectorclock order by DATABASEVERSION_ID asc, CLIENT asc
29-3-20 17:53:28.562 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from filecontent order by CHECKSUM asc
29-3-20 17:53:28.563 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILECONTENT_CHECKSUM, CHUNK_CHECKSUM, NUM from filecontent_chunk order by FILECONTENT_CHECKSUM asc, CHUNK_CHECKSUM asc, NUM asc
29-3-20 17:53:28.563 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID from filehistory order by ID asc, DATABASEVERSION_ID asc
29-3-20 17:53:28.564 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILEHISTORY_ID, VERSION, PATH, TYPE, STATUS, SIZE, LASTMODIFIED, LINKTARGET, FILECONTENT_CHECKSUM, UPDATED, POSIXPERMS, DOSATTRS from fileversion order by FILEHISTORY_ID asc, VERSION asc, DATABASEVERSION_ID asc
29-3-20 17:53:28.564 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID, SIZE from multichunk order by ID asc
29-3-20 17:53:28.565 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select MULTICHUNK_ID, CHUNK_CHECKSUM from multichunk_chunk order by MULTICHUNK_ID asc, CHUNK_CHECKSUM asc
29-3-20 17:53:28.565 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.565 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-B' ...
29-3-20 17:53:28.566 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.566 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.566 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.566 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.566 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.566 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.566 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.566 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.566 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.566 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-B' ...
29-3-20 17:53:28.566 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.566 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.566 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:28.566 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:28.566 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.566 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.567 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.567 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.567 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.567 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.567 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:28.567 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:28.568 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.568 | UpOperation     | Test worker    | INFO : 
29-3-20 17:53:28.568 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client B ...
29-3-20 17:53:28.568 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.568 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@a52d517) ...
29-3-20 17:53:28.568 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.568 | StatusOperation | Test worker    | INFO : 
29-3-20 17:53:28.568 | StatusOperation | Test worker    | INFO : Running 'Status' at client B ...
29-3-20 17:53:28.568 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.568 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:53:28.568 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@3f82cf93) ...
29-3-20 17:53:28.569 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-91297-client-B ...
29-3-20 17:53:28.569 | StatusOperation | Test worker    | FINE : - New file: B-moved
29-3-20 17:53:28.569 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:53:28.569 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@3db75514) ...
29-3-20 17:53:28.569 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:28.570 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.570 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:28.570 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
29-3-20 17:53:28.570 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.570 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@1b8cfd76) ...
29-3-20 17:53:28.570 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:28.570 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:28.570 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@f05c658) ...
29-3-20 17:53:28.570 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-3-20 17:53:28.570 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-B-1585504408567] ...
29-3-20 17:53:28.570 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-B-1585504408567]
29-3-20 17:53:28.571 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-B-1585504408567] ...
29-3-20 17:53:28.571 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.571 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-3-20 17:53:28.572 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-3-20 17:53:28.572 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@5f371a2) ...
29-3-20 17:53:28.572 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-3-20 17:53:28.573 | Indexer         | AsyncI/syncany | FINE :   + Deleted: Adding DELETED version: FileVersion [version=2, path=A-original, type=FILE, status=DELETED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.573 | Indexer         | AsyncI/syncany | FINE :                            based on: FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.573 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-200329175039872-91297-client-B/B-moved
29-3-20 17:53:28.573 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-200329175039872-91297-client-B/B-moved
29-3-20 17:53:28.589 | Indexer         | AsyncI/syncany | FINE : - Chunk exists: 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4
29-3-20 17:53:28.589 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4 > /tmp/syncanytest/syncany-200329175039872-91297-client-B/B-moved
29-3-20 17:53:28.589 | Indexer         | AsyncI/syncany | FINE : - /File: B-moved (checksum 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4)
29-3-20 17:53:28.590 | Indexer         | AsyncI/syncany | FINE :    * Found old file history 171db67cbbcd0a190ef9c702b2de0d4a1d387e49 (by checksum: 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4), appending new version.
29-3-20 17:53:28.590 | FileVersionComp | AsyncI/syncany | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = B-moved, but actual PATH = A-original, for file A-original
29-3-20 17:53:28.590 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.590 | Indexer         | AsyncI/syncany | INFO :      based on file version: FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.590 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@16160bb9) ...
29-3-20 17:53:28.590 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@1a3dcfdc) ...
29-3-20 17:53:28.590 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504408572, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:28.590 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-3-20 17:53:28.590 | UpOperation     | Test worker    | INFO : Last vector clock was: (A1)
29-3-20 17:53:28.591 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-3-20 17:53:28.591 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=B/(A1,B1)/T=1585504408591, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:28.591 | UpOperation     | Test worker    | INFO : Saving local delta database, version B/(A1,B1)/T=1585504408591 to file /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/database-B-0000000001 ... 
29-3-20 17:53:28.591 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/database-B-0000000001 ...
29-3-20 17:53:28.591 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-3-20 17:53:28.591 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/database-B-0000000001 to RemoteFile[name=database-B-0000000001] ...
29-3-20 17:53:28.591 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/database-B-0000000001 -> Temp. remote file: RemoteFile[name=temp-RXcMC-database-B-0000000001], final location: RemoteFile[name=database-B-0000000001]
29-3-20 17:53:28.592 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-3-20 17:53:28.592 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-3-20 17:53:28.593 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/temp-transaction-13030863875550288966.tmp
29-3-20 17:53:28.593 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@717b2a15) ...
29-3-20 17:53:28.593 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-7b6c1bdb] ...
29-3-20 17:53:28.594 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-3-20 17:53:28.594 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@7eac1f7f) ...
29-3-20 17:53:28.595 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/database-B-0000000001 to temp. file RemoteFile[name=temp-RXcMC-database-B-0000000001] ...
29-3-20 17:53:28.595 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@44c2f371) ...
29-3-20 17:53:28.596 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-RXcMC-database-B-0000000001] to final location RemoteFile[name=database-B-0000000001] ...
29-3-20 17:53:28.596 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-7b6c1bdb] ...
29-3-20 17:53:28.596 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-3-20 17:53:28.596 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-3-20 17:53:28.597 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version B/(A1,B1)/T=1585504408591) ...
29-3-20 17:53:28.598 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-3-20 17:53:28.602 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-3-20 17:53:28.605 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=B/(A1,B1)/T=1585504408591, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:28.605 | UpOperation     | Test worker    | INFO : Committing local database.
29-3-20 17:53:28.605 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-3-20 17:53:28.605 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504408602, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-3-20 17:53:28.605 | UpOperation     | Test worker    | INFO : Sync up done.
29-3-20 17:53:28.606 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-B-1585504408567] ...
29-3-20 17:53:28.611 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-B-1585504408567]
29-3-20 17:53:28.611 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:28.611 | Cache           | Test worker    | INFO : Cache size okay (52 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:28.611 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@436a7cdf) ...
29-3-20 17:53:28.611 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.611 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-A' ...
29-3-20 17:53:28.611 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.611 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.611 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.611 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.611 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.611 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.611 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.611 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.611 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.612 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-A' ...
29-3-20 17:53:28.612 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.612 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.612 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:28.612 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:28.612 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.612 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.612 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.612 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.612 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.612 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.612 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:28.612 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:28.616 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.616 | DownOperation   | Test worker    | INFO : 
29-3-20 17:53:28.616 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client A ...
29-3-20 17:53:28.616 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.616 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@762b6d81) ...
29-3-20 17:53:28.617 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:28.617 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.617 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:28.617 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:53:28.617 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.617 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@5ca53aa9) ...
29-3-20 17:53:28.617 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:28.617 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:28.617 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is new.
29-3-20 17:53:28.617 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@298061ff) ...
29-3-20 17:53:28.618 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@2ce79539) ...
29-3-20 17:53:28.618 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-A-1585504408612] ...
29-3-20 17:53:28.618 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-A-1585504408612]
29-3-20 17:53:28.618 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-A-1585504408612] ...
29-3-20 17:53:28.618 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
29-3-20 17:53:28.618 | DownOperation   | Test worker    | INFO : - Downloading database-B-0000000001 to local cache at /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-B-0000000001
29-3-20 17:53:28.618 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@25671bb9) ...
29-3-20 17:53:28.618 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
29-3-20 17:53:28.618 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-B-0000000001 ...
29-3-20 17:53:28.620 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A1,B1)/T=1585504408591
29-3-20 17:53:28.620 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-91297-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:28.620 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-91297-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:28.620 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
29-3-20 17:53:28.620 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1585504408436], B=[B/(A1,B1)/T=1585504408591]}
29-3-20 17:53:28.620 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
29-3-20 17:53:28.620 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1585504408436
29-3-20 17:53:28.620 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A1,B1)/T=1585504408591
29-3-20 17:53:28.620 | DatabaseReconci | Test worker    | INFO : - Winner is B with branch: 
29-3-20 17:53:28.620 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1585504408436
29-3-20 17:53:28.620 | DatabaseReconci | Test worker    | INFO :   + B/(A1,B1)/T=1585504408591
29-3-20 17:53:28.620 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
29-3-20 17:53:28.620 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
29-3-20 17:53:28.620 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
29-3-20 17:53:28.620 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1585504408436]
29-3-20 17:53:28.620 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1585504408436, B/(A1,B1)/T=1585504408591]
29-3-20 17:53:28.620 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
29-3-20 17:53:28.620 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [B/(A1,B1)/T=1585504408591]
29-3-20 17:53:28.620 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
29-3-20 17:53:28.620 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-B-0000000001 ...
29-3-20 17:53:28.621 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A1,B1)/T=1585504408591
29-3-20 17:53:28.622 | DownOperation   | Test worker    | INFO : Determine file system actions ...
29-3-20 17:53:28.622 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.625 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
29-3-20 17:53:28.625 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
29-3-20 17:53:28.625 | FileSystemActio | Test worker    | INFO :   + Comparing local version: FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.625 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.626 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = B-moved, but actual PATH = A-original, for file A-original
29-3-20 17:53:28.626 | FileSystemActio | Test worker    | INFO :      -> (12) Rename / Changed file attributes: Local file has different file attributes: local file = /tmp/syncanytest/syncany-200329175039872-91297-client-A/A-original, local version = FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-], winning version = FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.626 | FileSystemActio | Test worker    | INFO :      -> RenameFileSystemAction [file1=FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:28.626 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
29-3-20 17:53:28.626 | FileSystemActio | Test worker    | INFO :    Sorted actions:
29-3-20 17:53:28.626 | FileSystemActio | Test worker    | INFO :    + RenameFileSystemAction [file1=FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:28.626 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
29-3-20 17:53:28.626 | DownOperation   | Test worker    | FINE :    +  RenameFileSystemAction [file1=FileVersion [version=1, path=A-original, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:28.627 | FileSystemActio | Test worker    | INFO :      - (1) Renaming file /tmp/syncanytest/syncany-200329175039872-91297-client-A/A-original to /tmp/syncanytest/syncany-200329175039872-91297-client-A/B-moved ...
29-3-20 17:53:28.627 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
29-3-20 17:53:28.627 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
29-3-20 17:53:28.627 | DownOperation   | Test worker    | INFO :   + Applying database version (A1,B1)
29-3-20 17:53:28.627 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=B/(A1,B1)/T=1585504408591, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:28.636 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-A-1585504408612] ...
29-3-20 17:53:28.641 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-A-1585504408612]
29-3-20 17:53:28.642 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:28.642 | Cache           | Test worker    | INFO : Cache size okay (52 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:28.642 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@b3d6b47) ...
29-3-20 17:53:28.642 | DownOperation   | Test worker    | INFO : Sync down done.
29-3-20 17:53:28.645 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-200329175039872-91297-client-A/B-moved, but actual PATH = tmp/syncanytest/syncany-200329175039872-91297-client-B/B-moved, for file tmp/syncanytest/syncany-200329175039872-91297-client-B/B-moved
29-3-20 17:53:28.646 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.647 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.671 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from chunk order by CHECKSUM asc
29-3-20 17:53:28.672 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select STATUS, LOCALTIME, CLIENT, VECTORCLOCK_SERIALIZED from databaseversion order by ID asc
29-3-20 17:53:28.673 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CLIENT, LOGICALTIME from databaseversion_vectorclock order by DATABASEVERSION_ID asc, CLIENT asc
29-3-20 17:53:28.673 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from filecontent order by CHECKSUM asc
29-3-20 17:53:28.674 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILECONTENT_CHECKSUM, CHUNK_CHECKSUM, NUM from filecontent_chunk order by FILECONTENT_CHECKSUM asc, CHUNK_CHECKSUM asc, NUM asc
29-3-20 17:53:28.674 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID from filehistory order by ID asc, DATABASEVERSION_ID asc
29-3-20 17:53:28.676 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILEHISTORY_ID, VERSION, PATH, TYPE, STATUS, SIZE, LASTMODIFIED, LINKTARGET, FILECONTENT_CHECKSUM, UPDATED, POSIXPERMS, DOSATTRS from fileversion order by FILEHISTORY_ID asc, VERSION asc, DATABASEVERSION_ID asc
29-3-20 17:53:28.677 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID, SIZE from multichunk order by ID asc
29-3-20 17:53:28.678 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select MULTICHUNK_ID, CHUNK_CHECKSUM from multichunk_chunk order by MULTICHUNK_ID asc, CHUNK_CHECKSUM asc
29-3-20 17:53:28.679 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.679 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-A' ...
29-3-20 17:53:28.679 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.679 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.679 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.679 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.679 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.679 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.679 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.679 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.680 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.680 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-A' ...
29-3-20 17:53:28.680 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.680 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.680 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:28.680 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:28.680 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.680 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.680 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.680 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.680 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.680 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.680 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:28.680 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:28.681 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.681 | UpOperation     | Test worker    | INFO : 
29-3-20 17:53:28.681 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
29-3-20 17:53:28.681 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.681 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@4d7f67a7) ...
29-3-20 17:53:28.682 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.682 | StatusOperation | Test worker    | INFO : 
29-3-20 17:53:28.682 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-3-20 17:53:28.682 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.682 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:53:28.682 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@5148de75) ...
29-3-20 17:53:28.682 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-91297-client-A ...
29-3-20 17:53:28.683 | StatusOperation | Test worker    | FINE : - New file: A-moved
29-3-20 17:53:28.683 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:53:28.683 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@2f7d8644) ...
29-3-20 17:53:28.683 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:28.683 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.683 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:28.683 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:53:28.683 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.683 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@7a60ff1f) ...
29-3-20 17:53:28.683 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:28.684 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:28.684 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:28.684 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@7c07386c) ...
29-3-20 17:53:28.684 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-3-20 17:53:28.684 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1585504408681] ...
29-3-20 17:53:28.684 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1585504408681]
29-3-20 17:53:28.685 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1585504408681] ...
29-3-20 17:53:28.686 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.686 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-3-20 17:53:28.686 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-3-20 17:53:28.686 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@1658b12b) ...
29-3-20 17:53:28.686 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-3-20 17:53:28.692 | Indexer         | AsyncI/syncany | FINE :   + Deleted: Adding DELETED version: FileVersion [version=3, path=B-moved, type=FILE, status=DELETED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.692 | Indexer         | AsyncI/syncany | FINE :                            based on: FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.692 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-200329175039872-91297-client-A/A-moved
29-3-20 17:53:28.692 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-200329175039872-91297-client-A/A-moved
29-3-20 17:53:28.693 | Indexer         | AsyncI/syncany | FINE : - Chunk exists: 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4
29-3-20 17:53:28.693 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4 > /tmp/syncanytest/syncany-200329175039872-91297-client-A/A-moved
29-3-20 17:53:28.693 | Indexer         | AsyncI/syncany | FINE : - /File: A-moved (checksum 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4)
29-3-20 17:53:28.694 | Indexer         | AsyncI/syncany | FINE :    * Found old file history 171db67cbbcd0a190ef9c702b2de0d4a1d387e49 (by checksum: 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4), appending new version.
29-3-20 17:53:28.694 | FileVersionComp | AsyncI/syncany | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = A-moved, but actual PATH = B-moved, for file B-moved
29-3-20 17:53:28.694 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.694 | Indexer         | AsyncI/syncany | INFO :      based on file version: FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.695 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@18b4c11e) ...
29-3-20 17:53:28.695 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@66ffade3) ...
29-3-20 17:53:28.695 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504408686, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:28.695 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-3-20 17:53:28.695 | UpOperation     | Test worker    | INFO : Last vector clock was: (A1,B1)
29-3-20 17:53:28.695 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-3-20 17:53:28.696 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A2,B1)/T=1585504408695, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:28.696 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A2,B1)/T=1585504408695 to file /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-A-0000000002 ... 
29-3-20 17:53:28.696 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-A-0000000002 ...
29-3-20 17:53:28.696 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-3-20 17:53:28.696 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-A-0000000002 to RemoteFile[name=database-A-0000000002] ...
29-3-20 17:53:28.696 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-A-0000000002 -> Temp. remote file: RemoteFile[name=temp-mvucr-database-A-0000000002], final location: RemoteFile[name=database-A-0000000002]
29-3-20 17:53:28.697 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-3-20 17:53:28.697 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-3-20 17:53:28.698 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/temp-transaction-7901233769036994591.tmp
29-3-20 17:53:28.698 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@6698a6ef) ...
29-3-20 17:53:28.698 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-34237bc6] ...
29-3-20 17:53:28.698 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-3-20 17:53:28.698 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@30319156) ...
29-3-20 17:53:28.698 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-A-0000000002 to temp. file RemoteFile[name=temp-mvucr-database-A-0000000002] ...
29-3-20 17:53:28.698 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-mvucr-database-A-0000000002] to final location RemoteFile[name=database-A-0000000002] ...
29-3-20 17:53:28.698 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-34237bc6] ...
29-3-20 17:53:28.698 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-3-20 17:53:28.698 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-3-20 17:53:28.698 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A2,B1)/T=1585504408695) ...
29-3-20 17:53:28.699 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-3-20 17:53:28.701 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@3430ad8f) ...
29-3-20 17:53:28.702 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A2,B1)/T=1585504408695, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:28.702 | UpOperation     | Test worker    | INFO : Committing local database.
29-3-20 17:53:28.703 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-3-20 17:53:28.704 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-3-20 17:53:28.704 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504408704, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-3-20 17:53:28.704 | UpOperation     | Test worker    | INFO : Sync up done.
29-3-20 17:53:28.705 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1585504408681] ...
29-3-20 17:53:28.706 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1585504408681]
29-3-20 17:53:28.706 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:28.706 | Cache           | Test worker    | INFO : Cache size okay (52 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:28.706 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@4d000db4) ...
29-3-20 17:53:28.706 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.706 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-B' ...
29-3-20 17:53:28.706 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.706 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.706 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.706 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.706 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.706 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.706 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.706 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.706 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.706 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-B' ...
29-3-20 17:53:28.706 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.706 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.706 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:28.706 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:28.706 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.706 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.706 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.706 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.706 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.706 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.707 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:28.707 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:28.707 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.707 | DownOperation   | Test worker    | INFO : 
29-3-20 17:53:28.707 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
29-3-20 17:53:28.707 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.707 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@70c89d30) ...
29-3-20 17:53:28.707 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:28.708 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.708 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:28.708 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
29-3-20 17:53:28.708 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.708 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@626a96b4) ...
29-3-20 17:53:28.708 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:28.708 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
29-3-20 17:53:28.708 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:28.708 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:28.708 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@16c91f9) ...
29-3-20 17:53:28.708 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@7cc1b2f3) ...
29-3-20 17:53:28.709 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1585504408707] ...
29-3-20 17:53:28.709 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1585504408707]
29-3-20 17:53:28.709 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1585504408707] ...
29-3-20 17:53:28.709 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
29-3-20 17:53:28.709 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000002 to local cache at /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/database-A-0000000002
29-3-20 17:53:28.709 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@5774204a) ...
29-3-20 17:53:28.709 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
29-3-20 17:53:28.709 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/database-A-0000000002 ...
29-3-20 17:53:28.710 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2,B1)/T=1585504408695
29-3-20 17:53:28.711 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-91297-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:28.711 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-91297-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:28.711 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-91297-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:28.711 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
29-3-20 17:53:28.711 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A2,B1)/T=1585504408695], B=[A/(A1)/T=1585504408436, B/(A1,B1)/T=1585504408591]}
29-3-20 17:53:28.711 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
29-3-20 17:53:28.711 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1585504408436
29-3-20 17:53:28.711 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A1,B1)/T=1585504408591
29-3-20 17:53:28.711 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2,B1)/T=1585504408695
29-3-20 17:53:28.711 | DatabaseReconci | Test worker    | INFO : - Winner is A with branch: 
29-3-20 17:53:28.711 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1585504408436
29-3-20 17:53:28.711 | DatabaseReconci | Test worker    | INFO :   + B/(A1,B1)/T=1585504408591
29-3-20 17:53:28.711 | DatabaseReconci | Test worker    | INFO :   + A/(A2,B1)/T=1585504408695
29-3-20 17:53:28.711 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
29-3-20 17:53:28.711 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
29-3-20 17:53:28.711 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
29-3-20 17:53:28.711 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1585504408436, B/(A1,B1)/T=1585504408591]
29-3-20 17:53:28.711 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1585504408436, B/(A1,B1)/T=1585504408591, A/(A2,B1)/T=1585504408695]
29-3-20 17:53:28.711 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
29-3-20 17:53:28.711 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A2,B1)/T=1585504408695]
29-3-20 17:53:28.711 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
29-3-20 17:53:28.711 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/database-A-0000000002 ...
29-3-20 17:53:28.712 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2,B1)/T=1585504408695
29-3-20 17:53:28.712 | DownOperation   | Test worker    | INFO : Determine file system actions ...
29-3-20 17:53:28.713 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.714 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
29-3-20 17:53:28.714 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
29-3-20 17:53:28.714 | FileSystemActio | Test worker    | INFO :   + Comparing local version: FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.714 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.714 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = A-moved, but actual PATH = B-moved, for file B-moved
29-3-20 17:53:28.715 | FileSystemActio | Test worker    | INFO :      -> (12) Rename / Changed file attributes: Local file has different file attributes: local file = /tmp/syncanytest/syncany-200329175039872-91297-client-B/B-moved, local version = FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-], winning version = FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.715 | FileSystemActio | Test worker    | INFO :      -> RenameFileSystemAction [file1=FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:28.715 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
29-3-20 17:53:28.715 | FileSystemActio | Test worker    | INFO :    Sorted actions:
29-3-20 17:53:28.715 | FileSystemActio | Test worker    | INFO :    + RenameFileSystemAction [file1=FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:28.715 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
29-3-20 17:53:28.715 | DownOperation   | Test worker    | FINE :    +  RenameFileSystemAction [file1=FileVersion [version=2, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:28.716 | FileSystemActio | Test worker    | INFO :      - (1) Renaming file /tmp/syncanytest/syncany-200329175039872-91297-client-B/B-moved to /tmp/syncanytest/syncany-200329175039872-91297-client-B/A-moved ...
29-3-20 17:53:28.716 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
29-3-20 17:53:28.716 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
29-3-20 17:53:28.716 | DownOperation   | Test worker    | INFO :   + Applying database version (A2,B1)
29-3-20 17:53:28.716 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A2,B1)/T=1585504408695, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:28.720 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1585504408707] ...
29-3-20 17:53:28.725 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1585504408707]
29-3-20 17:53:28.725 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:28.725 | Cache           | Test worker    | INFO : Cache size okay (52 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:28.725 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@4a0464b8) ...
29-3-20 17:53:28.725 | DownOperation   | Test worker    | INFO : Sync down done.
29-3-20 17:53:28.729 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-200329175039872-91297-client-A/A-moved, but actual PATH = tmp/syncanytest/syncany-200329175039872-91297-client-B/A-moved, for file tmp/syncanytest/syncany-200329175039872-91297-client-B/A-moved
29-3-20 17:53:28.729 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.730 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.750 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from chunk order by CHECKSUM asc
29-3-20 17:53:28.750 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select STATUS, LOCALTIME, CLIENT, VECTORCLOCK_SERIALIZED from databaseversion order by ID asc
29-3-20 17:53:28.751 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CLIENT, LOGICALTIME from databaseversion_vectorclock order by DATABASEVERSION_ID asc, CLIENT asc
29-3-20 17:53:28.752 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from filecontent order by CHECKSUM asc
29-3-20 17:53:28.752 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILECONTENT_CHECKSUM, CHUNK_CHECKSUM, NUM from filecontent_chunk order by FILECONTENT_CHECKSUM asc, CHUNK_CHECKSUM asc, NUM asc
29-3-20 17:53:28.752 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID from filehistory order by ID asc, DATABASEVERSION_ID asc
29-3-20 17:53:28.753 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILEHISTORY_ID, VERSION, PATH, TYPE, STATUS, SIZE, LASTMODIFIED, LINKTARGET, FILECONTENT_CHECKSUM, UPDATED, POSIXPERMS, DOSATTRS from fileversion order by FILEHISTORY_ID asc, VERSION asc, DATABASEVERSION_ID asc
29-3-20 17:53:28.754 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID, SIZE from multichunk order by ID asc
29-3-20 17:53:28.754 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select MULTICHUNK_ID, CHUNK_CHECKSUM from multichunk_chunk order by MULTICHUNK_ID asc, CHUNK_CHECKSUM asc
29-3-20 17:53:28.755 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.755 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-A' ...
29-3-20 17:53:28.755 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.755 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.755 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.755 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.755 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.755 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.755 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.755 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.755 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.755 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-A' ...
29-3-20 17:53:28.755 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.756 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.756 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:28.756 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:28.756 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.756 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.756 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.756 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.756 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.756 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.756 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:28.756 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:28.767 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.767 | DownOperation   | Test worker    | INFO : 
29-3-20 17:53:28.767 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client A ...
29-3-20 17:53:28.767 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.767 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@341c064b) ...
29-3-20 17:53:28.767 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:28.767 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.767 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:28.767 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:53:28.768 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.768 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@316b25d1) ...
29-3-20 17:53:28.768 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:28.768 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-3-20 17:53:28.768 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:28.768 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:28.768 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@46267e0e) ...
29-3-20 17:53:28.768 | DownOperation   | Test worker    | INFO : * Nothing new. Skipping down operation.
29-3-20 17:53:28.768 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@25733d25) ...
29-3-20 17:53:28.772 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-200329175039872-91297-client-A/A-moved, but actual PATH = tmp/syncanytest/syncany-200329175039872-91297-client-B/A-moved, for file tmp/syncanytest/syncany-200329175039872-91297-client-B/A-moved
29-3-20 17:53:28.772 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.773 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.805 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from chunk order by CHECKSUM asc
29-3-20 17:53:28.811 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select STATUS, LOCALTIME, CLIENT, VECTORCLOCK_SERIALIZED from databaseversion order by ID asc
29-3-20 17:53:28.812 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CLIENT, LOGICALTIME from databaseversion_vectorclock order by DATABASEVERSION_ID asc, CLIENT asc
29-3-20 17:53:28.813 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from filecontent order by CHECKSUM asc
29-3-20 17:53:28.816 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILECONTENT_CHECKSUM, CHUNK_CHECKSUM, NUM from filecontent_chunk order by FILECONTENT_CHECKSUM asc, CHUNK_CHECKSUM asc, NUM asc
29-3-20 17:53:28.817 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID from filehistory order by ID asc, DATABASEVERSION_ID asc
29-3-20 17:53:28.817 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILEHISTORY_ID, VERSION, PATH, TYPE, STATUS, SIZE, LASTMODIFIED, LINKTARGET, FILECONTENT_CHECKSUM, UPDATED, POSIXPERMS, DOSATTRS from fileversion order by FILEHISTORY_ID asc, VERSION asc, DATABASEVERSION_ID asc
29-3-20 17:53:28.818 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID, SIZE from multichunk order by ID asc
29-3-20 17:53:28.818 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select MULTICHUNK_ID, CHUNK_CHECKSUM from multichunk_chunk order by MULTICHUNK_ID asc, CHUNK_CHECKSUM asc
29-3-20 17:53:28.820 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.820 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-A' ...
29-3-20 17:53:28.820 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.820 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.820 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.820 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.820 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.820 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.820 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.821 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.821 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.821 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-A' ...
29-3-20 17:53:28.821 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.821 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.821 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:28.821 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:28.821 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.821 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.821 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.821 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.821 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.821 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.821 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:28.821 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:28.828 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.828 | UpOperation     | Test worker    | INFO : 
29-3-20 17:53:28.828 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
29-3-20 17:53:28.828 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.828 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@4fdc3c2d) ...
29-3-20 17:53:28.829 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.829 | StatusOperation | Test worker    | INFO : 
29-3-20 17:53:28.829 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-3-20 17:53:28.829 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.829 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:53:28.829 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@4b0996cb) ...
29-3-20 17:53:28.830 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-91297-client-A ...
29-3-20 17:53:28.830 | StatusOperation | Test worker    | FINE : - New file: A-moved-again
29-3-20 17:53:28.830 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:53:28.830 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@477049b6) ...
29-3-20 17:53:28.830 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:28.831 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.831 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:28.831 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:53:28.831 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.831 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@43adc1d8) ...
29-3-20 17:53:28.831 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:28.831 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-3-20 17:53:28.831 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:28.831 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:28.831 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@7de81dd0) ...
29-3-20 17:53:28.832 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-3-20 17:53:28.832 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1585504408821] ...
29-3-20 17:53:28.832 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1585504408821]
29-3-20 17:53:28.832 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1585504408821] ...
29-3-20 17:53:28.832 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.836 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-3-20 17:53:28.836 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-3-20 17:53:28.836 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@549212e2) ...
29-3-20 17:53:28.836 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-3-20 17:53:28.837 | Indexer         | AsyncI/syncany | FINE :   + Deleted: Adding DELETED version: FileVersion [version=4, path=A-moved, type=FILE, status=DELETED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.837 | Indexer         | AsyncI/syncany | FINE :                            based on: FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.837 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-200329175039872-91297-client-A/A-moved-again
29-3-20 17:53:28.837 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-200329175039872-91297-client-A/A-moved-again
29-3-20 17:53:28.838 | Indexer         | AsyncI/syncany | FINE : - Chunk exists: 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4
29-3-20 17:53:28.840 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4 > /tmp/syncanytest/syncany-200329175039872-91297-client-A/A-moved-again
29-3-20 17:53:28.840 | Indexer         | AsyncI/syncany | FINE : - /File: A-moved-again (checksum 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4)
29-3-20 17:53:28.841 | Indexer         | AsyncI/syncany | FINE :    * Found old file history 171db67cbbcd0a190ef9c702b2de0d4a1d387e49 (by checksum: 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4), appending new version.
29-3-20 17:53:28.841 | FileVersionComp | AsyncI/syncany | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = A-moved-again, but actual PATH = A-moved, for file A-moved
29-3-20 17:53:28.841 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.841 | Indexer         | AsyncI/syncany | INFO :      based on file version: FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.841 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@66145851) ...
29-3-20 17:53:28.848 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@2766dfb) ...
29-3-20 17:53:28.848 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504408836, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:28.848 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-3-20 17:53:28.848 | UpOperation     | Test worker    | INFO : Last vector clock was: (A2,B1)
29-3-20 17:53:28.849 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-3-20 17:53:28.849 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A3,B1)/T=1585504408849, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:28.849 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A3,B1)/T=1585504408849 to file /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-A-0000000003 ... 
29-3-20 17:53:28.849 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-A-0000000003 ...
29-3-20 17:53:28.849 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-3-20 17:53:28.849 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-A-0000000003 to RemoteFile[name=database-A-0000000003] ...
29-3-20 17:53:28.849 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-A-0000000003 -> Temp. remote file: RemoteFile[name=temp-kgIwG-database-A-0000000003], final location: RemoteFile[name=database-A-0000000003]
29-3-20 17:53:28.849 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-3-20 17:53:28.849 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-3-20 17:53:28.850 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/temp-transaction-3317788825676399127.tmp
29-3-20 17:53:28.850 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@483ed762) ...
29-3-20 17:53:28.850 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-6d8d883c] ...
29-3-20 17:53:28.851 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-3-20 17:53:28.851 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@7ccb9d63) ...
29-3-20 17:53:28.851 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-A-0000000003 to temp. file RemoteFile[name=temp-kgIwG-database-A-0000000003] ...
29-3-20 17:53:28.851 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-kgIwG-database-A-0000000003] to final location RemoteFile[name=database-A-0000000003] ...
29-3-20 17:53:28.851 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-6d8d883c] ...
29-3-20 17:53:28.851 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-3-20 17:53:28.851 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-3-20 17:53:28.851 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A3,B1)/T=1585504408849) ...
29-3-20 17:53:28.852 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-3-20 17:53:28.854 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@844d59e) ...
29-3-20 17:53:28.856 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A3,B1)/T=1585504408849, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:28.856 | UpOperation     | Test worker    | INFO : Committing local database.
29-3-20 17:53:28.856 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-3-20 17:53:28.857 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-3-20 17:53:28.857 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504408857, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-3-20 17:53:28.857 | UpOperation     | Test worker    | INFO : Sync up done.
29-3-20 17:53:28.859 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1585504408821] ...
29-3-20 17:53:28.864 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1585504408821]
29-3-20 17:53:28.864 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:28.864 | Cache           | Test worker    | INFO : Cache size okay (53 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:28.864 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@553c67d) ...
29-3-20 17:53:28.864 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.864 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-B' ...
29-3-20 17:53:28.864 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.864 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.864 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.864 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.864 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.864 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.864 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.864 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.864 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.864 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-B' ...
29-3-20 17:53:28.864 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.864 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.864 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:28.864 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:28.864 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.864 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.864 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.865 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.865 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.865 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.865 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:28.865 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:28.868 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.869 | DownOperation   | Test worker    | INFO : 
29-3-20 17:53:28.869 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
29-3-20 17:53:28.869 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.869 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@40d4cf0e) ...
29-3-20 17:53:28.869 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:28.869 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.869 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:28.869 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
29-3-20 17:53:28.869 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.869 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@65e1a86d) ...
29-3-20 17:53:28.869 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:28.869 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-3-20 17:53:28.869 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is new.
29-3-20 17:53:28.869 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:28.869 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:28.869 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@4fcb7740) ...
29-3-20 17:53:28.869 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@6637ba55) ...
29-3-20 17:53:28.869 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1585504408865] ...
29-3-20 17:53:28.869 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1585504408865]
29-3-20 17:53:28.870 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1585504408865] ...
29-3-20 17:53:28.870 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
29-3-20 17:53:28.870 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000003 to local cache at /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/database-A-0000000003
29-3-20 17:53:28.870 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@3835b0e4) ...
29-3-20 17:53:28.870 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
29-3-20 17:53:28.870 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/database-A-0000000003 ...
29-3-20 17:53:28.872 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A3,B1)/T=1585504408849
29-3-20 17:53:28.872 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-91297-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:28.872 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-91297-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:28.872 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-91297-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:28.872 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-91297-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:28.873 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
29-3-20 17:53:28.873 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A3,B1)/T=1585504408849], B=[A/(A1)/T=1585504408436, B/(A1,B1)/T=1585504408591, A/(A2,B1)/T=1585504408695]}
29-3-20 17:53:28.873 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
29-3-20 17:53:28.873 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1585504408436
29-3-20 17:53:28.873 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A1,B1)/T=1585504408591
29-3-20 17:53:28.873 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2,B1)/T=1585504408695
29-3-20 17:53:28.873 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3,B1)/T=1585504408849
29-3-20 17:53:28.873 | DatabaseReconci | Test worker    | INFO : - Winner is A with branch: 
29-3-20 17:53:28.873 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1585504408436
29-3-20 17:53:28.873 | DatabaseReconci | Test worker    | INFO :   + B/(A1,B1)/T=1585504408591
29-3-20 17:53:28.873 | DatabaseReconci | Test worker    | INFO :   + A/(A2,B1)/T=1585504408695
29-3-20 17:53:28.873 | DatabaseReconci | Test worker    | INFO :   + A/(A3,B1)/T=1585504408849
29-3-20 17:53:28.873 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
29-3-20 17:53:28.873 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
29-3-20 17:53:28.873 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
29-3-20 17:53:28.874 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1585504408436, B/(A1,B1)/T=1585504408591, A/(A2,B1)/T=1585504408695]
29-3-20 17:53:28.874 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1585504408436, B/(A1,B1)/T=1585504408591, A/(A2,B1)/T=1585504408695, A/(A3,B1)/T=1585504408849]
29-3-20 17:53:28.874 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
29-3-20 17:53:28.874 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A3,B1)/T=1585504408849]
29-3-20 17:53:28.874 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
29-3-20 17:53:28.874 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/database-A-0000000003 ...
29-3-20 17:53:28.875 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A3,B1)/T=1585504408849
29-3-20 17:53:28.875 | DownOperation   | Test worker    | INFO : Determine file system actions ...
29-3-20 17:53:28.875 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.880 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
29-3-20 17:53:28.880 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
29-3-20 17:53:28.881 | FileSystemActio | Test worker    | INFO :   + Comparing local version: FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.881 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.881 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = A-moved-again, but actual PATH = A-moved, for file A-moved
29-3-20 17:53:28.881 | FileSystemActio | Test worker    | INFO :      -> (12) Rename / Changed file attributes: Local file has different file attributes: local file = /tmp/syncanytest/syncany-200329175039872-91297-client-B/A-moved, local version = FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-], winning version = FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.881 | FileSystemActio | Test worker    | INFO :      -> RenameFileSystemAction [file1=FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:28.882 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
29-3-20 17:53:28.882 | FileSystemActio | Test worker    | INFO :    Sorted actions:
29-3-20 17:53:28.882 | FileSystemActio | Test worker    | INFO :    + RenameFileSystemAction [file1=FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:28.882 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
29-3-20 17:53:28.882 | DownOperation   | Test worker    | FINE :    +  RenameFileSystemAction [file1=FileVersion [version=3, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:28.883 | FileSystemActio | Test worker    | INFO :      - (1) Renaming file /tmp/syncanytest/syncany-200329175039872-91297-client-B/A-moved to /tmp/syncanytest/syncany-200329175039872-91297-client-B/A-moved-again ...
29-3-20 17:53:28.883 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
29-3-20 17:53:28.883 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
29-3-20 17:53:28.883 | DownOperation   | Test worker    | INFO :   + Applying database version (A3,B1)
29-3-20 17:53:28.883 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A3,B1)/T=1585504408849, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:28.888 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1585504408865] ...
29-3-20 17:53:28.894 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1585504408865]
29-3-20 17:53:28.894 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:28.894 | Cache           | Test worker    | INFO : Cache size okay (53 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:28.894 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@278ca24c) ...
29-3-20 17:53:28.894 | DownOperation   | Test worker    | INFO : Sync down done.
29-3-20 17:53:28.898 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-200329175039872-91297-client-A/A-moved-again, but actual PATH = tmp/syncanytest/syncany-200329175039872-91297-client-B/A-moved-again, for file tmp/syncanytest/syncany-200329175039872-91297-client-B/A-moved-again
29-3-20 17:53:28.899 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.899 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.922 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from chunk order by CHECKSUM asc
29-3-20 17:53:28.923 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select STATUS, LOCALTIME, CLIENT, VECTORCLOCK_SERIALIZED from databaseversion order by ID asc
29-3-20 17:53:28.924 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CLIENT, LOGICALTIME from databaseversion_vectorclock order by DATABASEVERSION_ID asc, CLIENT asc
29-3-20 17:53:28.924 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from filecontent order by CHECKSUM asc
29-3-20 17:53:28.925 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILECONTENT_CHECKSUM, CHUNK_CHECKSUM, NUM from filecontent_chunk order by FILECONTENT_CHECKSUM asc, CHUNK_CHECKSUM asc, NUM asc
29-3-20 17:53:28.925 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID from filehistory order by ID asc, DATABASEVERSION_ID asc
29-3-20 17:53:28.926 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILEHISTORY_ID, VERSION, PATH, TYPE, STATUS, SIZE, LASTMODIFIED, LINKTARGET, FILECONTENT_CHECKSUM, UPDATED, POSIXPERMS, DOSATTRS from fileversion order by FILEHISTORY_ID asc, VERSION asc, DATABASEVERSION_ID asc
29-3-20 17:53:28.926 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID, SIZE from multichunk order by ID asc
29-3-20 17:53:28.927 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select MULTICHUNK_ID, CHUNK_CHECKSUM from multichunk_chunk order by MULTICHUNK_ID asc, CHUNK_CHECKSUM asc
29-3-20 17:53:28.927 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.928 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-B' ...
29-3-20 17:53:28.928 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.928 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.928 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.928 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.928 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.928 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.928 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.928 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.928 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.929 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-B' ...
29-3-20 17:53:28.929 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.929 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.929 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:28.929 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:28.929 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.929 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.929 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.929 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.929 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.929 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.929 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:28.929 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:28.940 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.940 | UpOperation     | Test worker    | INFO : 
29-3-20 17:53:28.941 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client B ...
29-3-20 17:53:28.941 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.941 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@1204e157) ...
29-3-20 17:53:28.941 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.941 | StatusOperation | Test worker    | INFO : 
29-3-20 17:53:28.941 | StatusOperation | Test worker    | INFO : Running 'Status' at client B ...
29-3-20 17:53:28.941 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.941 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:53:28.942 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@33e65a7) ...
29-3-20 17:53:28.942 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-91297-client-B ...
29-3-20 17:53:28.942 | StatusOperation | Test worker    | FINE : - New file: B-moved
29-3-20 17:53:28.943 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:53:28.943 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@6ad41202) ...
29-3-20 17:53:28.943 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:28.943 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.944 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:28.944 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
29-3-20 17:53:28.944 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.944 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@11c545a8) ...
29-3-20 17:53:28.944 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:28.944 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-3-20 17:53:28.944 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
29-3-20 17:53:28.944 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:28.944 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:28.944 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@714026b6) ...
29-3-20 17:53:28.944 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-3-20 17:53:28.945 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-B-1585504408930] ...
29-3-20 17:53:28.945 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-B-1585504408930]
29-3-20 17:53:28.945 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-B-1585504408930] ...
29-3-20 17:53:28.946 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.952 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-3-20 17:53:28.953 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-3-20 17:53:28.953 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@55b1b25c) ...
29-3-20 17:53:28.953 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-3-20 17:53:28.954 | Indexer         | AsyncI/syncany | FINE :   + Deleted: Adding DELETED version: FileVersion [version=5, path=A-moved-again, type=FILE, status=DELETED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.954 | Indexer         | AsyncI/syncany | FINE :                            based on: FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.954 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-200329175039872-91297-client-B/B-moved
29-3-20 17:53:28.954 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-200329175039872-91297-client-B/B-moved
29-3-20 17:53:28.955 | Indexer         | AsyncI/syncany | FINE : - Chunk exists: 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4
29-3-20 17:53:28.955 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4 > /tmp/syncanytest/syncany-200329175039872-91297-client-B/B-moved
29-3-20 17:53:28.956 | Indexer         | AsyncI/syncany | FINE : - /File: B-moved (checksum 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4)
29-3-20 17:53:28.959 | Indexer         | AsyncI/syncany | FINE :    * Found old file history 171db67cbbcd0a190ef9c702b2de0d4a1d387e49 (by checksum: 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4), appending new version.
29-3-20 17:53:28.959 | FileVersionComp | AsyncI/syncany | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = B-moved, but actual PATH = A-moved-again, for file A-moved-again
29-3-20 17:53:28.959 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.959 | Indexer         | AsyncI/syncany | INFO :      based on file version: FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.959 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@5f0669cd) ...
29-3-20 17:53:28.964 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@4e7deb80) ...
29-3-20 17:53:28.964 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504408953, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:28.964 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-3-20 17:53:28.964 | UpOperation     | Test worker    | INFO : Last vector clock was: (A3,B1)
29-3-20 17:53:28.965 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-3-20 17:53:28.965 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=B/(A3,B2)/T=1585504408965, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:28.965 | UpOperation     | Test worker    | INFO : Saving local delta database, version B/(A3,B2)/T=1585504408965 to file /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/database-B-0000000002 ... 
29-3-20 17:53:28.965 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/database-B-0000000002 ...
29-3-20 17:53:28.965 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-3-20 17:53:28.965 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/database-B-0000000002 to RemoteFile[name=database-B-0000000002] ...
29-3-20 17:53:28.966 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/database-B-0000000002 -> Temp. remote file: RemoteFile[name=temp-qYFgN-database-B-0000000002], final location: RemoteFile[name=database-B-0000000002]
29-3-20 17:53:28.966 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-3-20 17:53:28.966 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-3-20 17:53:28.967 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/temp-transaction-9252805687067690902.tmp
29-3-20 17:53:28.967 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@173abda1) ...
29-3-20 17:53:28.967 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-66ef6291] ...
29-3-20 17:53:28.967 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-3-20 17:53:28.967 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@6d081793) ...
29-3-20 17:53:28.967 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/database-B-0000000002 to temp. file RemoteFile[name=temp-qYFgN-database-B-0000000002] ...
29-3-20 17:53:28.967 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-qYFgN-database-B-0000000002] to final location RemoteFile[name=database-B-0000000002] ...
29-3-20 17:53:28.968 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-66ef6291] ...
29-3-20 17:53:28.968 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-3-20 17:53:28.968 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-3-20 17:53:28.968 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version B/(A3,B2)/T=1585504408965) ...
29-3-20 17:53:28.968 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-3-20 17:53:28.970 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@1bd8c843) ...
29-3-20 17:53:28.972 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=B/(A3,B2)/T=1585504408965, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:28.972 | UpOperation     | Test worker    | INFO : Committing local database.
29-3-20 17:53:28.972 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-3-20 17:53:28.973 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-3-20 17:53:28.973 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504408973, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-3-20 17:53:28.973 | UpOperation     | Test worker    | INFO : Sync up done.
29-3-20 17:53:28.975 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-B-1585504408930] ...
29-3-20 17:53:28.980 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-B-1585504408930]
29-3-20 17:53:28.980 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:28.980 | Cache           | Test worker    | INFO : Cache size okay (54 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:28.980 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@39c4e4c5) ...
29-3-20 17:53:28.980 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.980 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-A' ...
29-3-20 17:53:28.981 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.981 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.981 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.981 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.981 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.981 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.981 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.981 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.981 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:28.981 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-A' ...
29-3-20 17:53:28.981 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:28.981 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:28.981 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:28.981 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:28.981 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:28.981 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:28.981 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:28.981 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:28.981 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:28.981 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:28.981 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:28.981 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:28.988 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.988 | DownOperation   | Test worker    | INFO : 
29-3-20 17:53:28.988 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client A ...
29-3-20 17:53:28.988 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.988 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@2935873) ...
29-3-20 17:53:28.988 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:28.989 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.989 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:28.989 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:53:28.989 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:28.989 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@52c13ea8) ...
29-3-20 17:53:28.989 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:28.989 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-3-20 17:53:28.989 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
29-3-20 17:53:28.989 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000002 is new.
29-3-20 17:53:28.989 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:28.989 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:28.989 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@2af1aec8) ...
29-3-20 17:53:28.989 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@ea1f689) ...
29-3-20 17:53:28.989 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-A-1585504408981] ...
29-3-20 17:53:28.990 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-A-1585504408981]
29-3-20 17:53:28.990 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-A-1585504408981] ...
29-3-20 17:53:28.990 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
29-3-20 17:53:28.990 | DownOperation   | Test worker    | INFO : - Downloading database-B-0000000002 to local cache at /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-B-0000000002
29-3-20 17:53:28.990 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@96d7bb9) ...
29-3-20 17:53:28.991 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
29-3-20 17:53:28.991 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-B-0000000002 ...
29-3-20 17:53:28.992 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A3,B2)/T=1585504408965
29-3-20 17:53:28.992 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-91297-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:28.992 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-91297-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:28.992 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-91297-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:28.992 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-91297-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:28.992 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-91297-repo/databases/database-B-0000000002; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:28.992 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
29-3-20 17:53:28.992 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1585504408436, B/(A1,B1)/T=1585504408591, A/(A2,B1)/T=1585504408695, A/(A3,B1)/T=1585504408849], B=[B/(A3,B2)/T=1585504408965]}
29-3-20 17:53:28.993 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
29-3-20 17:53:28.993 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1585504408436
29-3-20 17:53:28.993 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A1,B1)/T=1585504408591
29-3-20 17:53:28.993 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2,B1)/T=1585504408695
29-3-20 17:53:28.993 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3,B1)/T=1585504408849
29-3-20 17:53:28.993 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A3,B2)/T=1585504408965
29-3-20 17:53:28.993 | DatabaseReconci | Test worker    | INFO : - Winner is B with branch: 
29-3-20 17:53:28.993 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1585504408436
29-3-20 17:53:28.993 | DatabaseReconci | Test worker    | INFO :   + B/(A1,B1)/T=1585504408591
29-3-20 17:53:28.993 | DatabaseReconci | Test worker    | INFO :   + A/(A2,B1)/T=1585504408695
29-3-20 17:53:28.993 | DatabaseReconci | Test worker    | INFO :   + A/(A3,B1)/T=1585504408849
29-3-20 17:53:28.993 | DatabaseReconci | Test worker    | INFO :   + B/(A3,B2)/T=1585504408965
29-3-20 17:53:28.993 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
29-3-20 17:53:28.993 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
29-3-20 17:53:28.993 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
29-3-20 17:53:28.993 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1585504408436, B/(A1,B1)/T=1585504408591, A/(A2,B1)/T=1585504408695, A/(A3,B1)/T=1585504408849]
29-3-20 17:53:28.993 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1585504408436, B/(A1,B1)/T=1585504408591, A/(A2,B1)/T=1585504408695, A/(A3,B1)/T=1585504408849, B/(A3,B2)/T=1585504408965]
29-3-20 17:53:28.993 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
29-3-20 17:53:28.993 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [B/(A3,B2)/T=1585504408965]
29-3-20 17:53:28.993 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
29-3-20 17:53:28.993 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-B-0000000002 ...
29-3-20 17:53:28.994 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A3,B2)/T=1585504408965
29-3-20 17:53:28.994 | DownOperation   | Test worker    | INFO : Determine file system actions ...
29-3-20 17:53:28.994 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:28.995 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
29-3-20 17:53:28.995 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
29-3-20 17:53:28.995 | FileSystemActio | Test worker    | INFO :   + Comparing local version: FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.995 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.996 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = B-moved, but actual PATH = A-moved-again, for file A-moved-again
29-3-20 17:53:28.997 | FileSystemActio | Test worker    | INFO :      -> (12) Rename / Changed file attributes: Local file has different file attributes: local file = /tmp/syncanytest/syncany-200329175039872-91297-client-A/A-moved-again, local version = FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-], winning version = FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:28.997 | FileSystemActio | Test worker    | INFO :      -> RenameFileSystemAction [file1=FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:28.997 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
29-3-20 17:53:28.997 | FileSystemActio | Test worker    | INFO :    Sorted actions:
29-3-20 17:53:28.997 | FileSystemActio | Test worker    | INFO :    + RenameFileSystemAction [file1=FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:28.997 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
29-3-20 17:53:28.997 | DownOperation   | Test worker    | FINE :    +  RenameFileSystemAction [file1=FileVersion [version=4, path=A-moved-again, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:28.998 | FileSystemActio | Test worker    | INFO :      - (1) Renaming file /tmp/syncanytest/syncany-200329175039872-91297-client-A/A-moved-again to /tmp/syncanytest/syncany-200329175039872-91297-client-A/B-moved ...
29-3-20 17:53:28.998 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
29-3-20 17:53:28.998 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
29-3-20 17:53:28.998 | DownOperation   | Test worker    | INFO :   + Applying database version (A3,B2)
29-3-20 17:53:28.998 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=B/(A3,B2)/T=1585504408965, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:29.002 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-A-1585504408981] ...
29-3-20 17:53:29.002 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-A-1585504408981]
29-3-20 17:53:29.002 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:29.002 | Cache           | Test worker    | INFO : Cache size okay (54 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:29.002 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@1486d913) ...
29-3-20 17:53:29.002 | DownOperation   | Test worker    | INFO : Sync down done.
29-3-20 17:53:29.006 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-200329175039872-91297-client-A/B-moved, but actual PATH = tmp/syncanytest/syncany-200329175039872-91297-client-B/B-moved, for file tmp/syncanytest/syncany-200329175039872-91297-client-B/B-moved
29-3-20 17:53:29.007 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:29.012 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:29.041 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from chunk order by CHECKSUM asc
29-3-20 17:53:29.041 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select STATUS, LOCALTIME, CLIENT, VECTORCLOCK_SERIALIZED from databaseversion order by ID asc
29-3-20 17:53:29.045 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CLIENT, LOGICALTIME from databaseversion_vectorclock order by DATABASEVERSION_ID asc, CLIENT asc
29-3-20 17:53:29.046 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from filecontent order by CHECKSUM asc
29-3-20 17:53:29.057 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILECONTENT_CHECKSUM, CHUNK_CHECKSUM, NUM from filecontent_chunk order by FILECONTENT_CHECKSUM asc, CHUNK_CHECKSUM asc, NUM asc
29-3-20 17:53:29.059 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID from filehistory order by ID asc, DATABASEVERSION_ID asc
29-3-20 17:53:29.060 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILEHISTORY_ID, VERSION, PATH, TYPE, STATUS, SIZE, LASTMODIFIED, LINKTARGET, FILECONTENT_CHECKSUM, UPDATED, POSIXPERMS, DOSATTRS from fileversion order by FILEHISTORY_ID asc, VERSION asc, DATABASEVERSION_ID asc
29-3-20 17:53:29.061 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID, SIZE from multichunk order by ID asc
29-3-20 17:53:29.062 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select MULTICHUNK_ID, CHUNK_CHECKSUM from multichunk_chunk order by MULTICHUNK_ID asc, CHUNK_CHECKSUM asc
29-3-20 17:53:29.062 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:29.063 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-A' ...
29-3-20 17:53:29.063 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:29.063 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:29.063 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:29.063 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:29.063 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:29.063 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:29.063 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:29.063 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:29.063 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:29.063 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-A' ...
29-3-20 17:53:29.063 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:29.063 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:29.063 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:29.063 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:29.063 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:29.063 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:29.063 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:29.063 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:29.063 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:29.063 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:29.063 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:29.063 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:29.065 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:29.065 | UpOperation     | Test worker    | INFO : 
29-3-20 17:53:29.065 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
29-3-20 17:53:29.065 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:29.065 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@5ed27192) ...
29-3-20 17:53:29.065 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:29.065 | StatusOperation | Test worker    | INFO : 
29-3-20 17:53:29.065 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-3-20 17:53:29.065 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:29.065 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:53:29.065 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@1309c37a) ...
29-3-20 17:53:29.066 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-91297-client-A ...
29-3-20 17:53:29.066 | StatusOperation | Test worker    | FINE : - New file: A-moved
29-3-20 17:53:29.066 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:53:29.066 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@4f208787) ...
29-3-20 17:53:29.066 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:29.067 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:29.067 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:29.067 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:53:29.067 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:29.067 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@2ddb3d5b) ...
29-3-20 17:53:29.067 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:29.067 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-3-20 17:53:29.067 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
29-3-20 17:53:29.067 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000002 is already known (in local database). Ignoring.
29-3-20 17:53:29.067 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:29.067 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:29.067 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@6d37b173) ...
29-3-20 17:53:29.067 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-3-20 17:53:29.067 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1585504409063] ...
29-3-20 17:53:29.067 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1585504409063]
29-3-20 17:53:29.068 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1585504409063] ...
29-3-20 17:53:29.068 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:29.072 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-3-20 17:53:29.072 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-3-20 17:53:29.072 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@5f67e667) ...
29-3-20 17:53:29.072 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-3-20 17:53:29.073 | Indexer         | AsyncI/syncany | FINE :   + Deleted: Adding DELETED version: FileVersion [version=6, path=B-moved, type=FILE, status=DELETED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:29 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:29.073 | Indexer         | AsyncI/syncany | FINE :                            based on: FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:29.073 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-200329175039872-91297-client-A/A-moved
29-3-20 17:53:29.074 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-200329175039872-91297-client-A/A-moved
29-3-20 17:53:29.075 | Indexer         | AsyncI/syncany | FINE : - Chunk exists: 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4
29-3-20 17:53:29.075 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4 > /tmp/syncanytest/syncany-200329175039872-91297-client-A/A-moved
29-3-20 17:53:29.075 | Indexer         | AsyncI/syncany | FINE : - /File: A-moved (checksum 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4)
29-3-20 17:53:29.077 | Indexer         | AsyncI/syncany | FINE :    * Found old file history 171db67cbbcd0a190ef9c702b2de0d4a1d387e49 (by checksum: 667fca1eab4ae9dcb59000e6d339cb71b01ea3d4), appending new version.
29-3-20 17:53:29.077 | FileVersionComp | AsyncI/syncany | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = A-moved, but actual PATH = B-moved, for file B-moved
29-3-20 17:53:29.077 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=6, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:29 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:29.077 | Indexer         | AsyncI/syncany | INFO :      based on file version: FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:29.077 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@7f809b3a) ...
29-3-20 17:53:29.077 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@682a7e65) ...
29-3-20 17:53:29.099 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504409072, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:29.099 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@5e2d8731) ...
29-3-20 17:53:29.099 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-3-20 17:53:29.099 | UpOperation     | Test worker    | INFO : Last vector clock was: (A3,B2)
29-3-20 17:53:29.100 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-3-20 17:53:29.100 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A4,B2)/T=1585504409100, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:29.100 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A4,B2)/T=1585504409100 to file /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-A-0000000004 ... 
29-3-20 17:53:29.100 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-A-0000000004 ...
29-3-20 17:53:29.100 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-3-20 17:53:29.100 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-A-0000000004 to RemoteFile[name=database-A-0000000004] ...
29-3-20 17:53:29.100 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-A-0000000004 -> Temp. remote file: RemoteFile[name=temp-subnI-database-A-0000000004], final location: RemoteFile[name=database-A-0000000004]
29-3-20 17:53:29.101 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-3-20 17:53:29.101 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-3-20 17:53:29.101 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/temp-transaction-16661864106649932085.tmp
29-3-20 17:53:29.102 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@c311fab) ...
29-3-20 17:53:29.102 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-3160356c] ...
29-3-20 17:53:29.102 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-3-20 17:53:29.102 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@6134a01) ...
29-3-20 17:53:29.102 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-91297-client-A/.syncany/cache/database-A-0000000004 to temp. file RemoteFile[name=temp-subnI-database-A-0000000004] ...
29-3-20 17:53:29.104 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-3-20 17:53:29.108 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-subnI-database-A-0000000004] to final location RemoteFile[name=database-A-0000000004] ...
29-3-20 17:53:29.108 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-3160356c] ...
29-3-20 17:53:29.108 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-3-20 17:53:29.108 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-3-20 17:53:29.108 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A4,B2)/T=1585504409100) ...
29-3-20 17:53:29.109 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-3-20 17:53:29.117 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A4,B2)/T=1585504409100, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:29.117 | UpOperation     | Test worker    | INFO : Committing local database.
29-3-20 17:53:29.117 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-3-20 17:53:29.117 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504409104, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-3-20 17:53:29.117 | UpOperation     | Test worker    | INFO : Sync up done.
29-3-20 17:53:29.119 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1585504409063] ...
29-3-20 17:53:29.124 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1585504409063]
29-3-20 17:53:29.124 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:29.124 | Cache           | Test worker    | INFO : Cache size okay (54 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:29.124 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@1ae6a485) ...
29-3-20 17:53:29.124 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:29.124 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-B' ...
29-3-20 17:53:29.124 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:29.124 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:29.124 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:29.124 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:29.124 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:29.125 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:29.125 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:29.125 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:29.125 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:29.125 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-91297-client-B' ...
29-3-20 17:53:29.125 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:29.125 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:29.125 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:29.125 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:29.125 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:29.125 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:29.125 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:29.125 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:29.125 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:29.125 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:29.125 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:29.125 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:29.129 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:29.129 | DownOperation   | Test worker    | INFO : 
29-3-20 17:53:29.129 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
29-3-20 17:53:29.129 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:29.129 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@57032d95) ...
29-3-20 17:53:29.129 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:29.130 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:29.130 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:29.130 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
29-3-20 17:53:29.130 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:29.130 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@776c394d) ...
29-3-20 17:53:29.130 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:29.130 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is new.
29-3-20 17:53:29.130 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-3-20 17:53:29.130 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
29-3-20 17:53:29.130 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000002 is already known (in local database). Ignoring.
29-3-20 17:53:29.130 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:29.130 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:29.130 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@428ab058) ...
29-3-20 17:53:29.130 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@11ba9791) ...
29-3-20 17:53:29.130 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1585504409125] ...
29-3-20 17:53:29.130 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1585504409125]
29-3-20 17:53:29.130 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1585504409125] ...
29-3-20 17:53:29.130 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
29-3-20 17:53:29.131 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000004 to local cache at /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/database-A-0000000004
29-3-20 17:53:29.131 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@46b6c638) ...
29-3-20 17:53:29.131 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
29-3-20 17:53:29.131 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/database-A-0000000004 ...
29-3-20 17:53:29.132 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A4,B2)/T=1585504409100
29-3-20 17:53:29.132 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-91297-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:29.132 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-91297-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:29.132 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-91297-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:29.132 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-91297-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:29.132 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-91297-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:29.132 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-91297-repo/databases/database-B-0000000002; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:29.133 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
29-3-20 17:53:29.133 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A4,B2)/T=1585504409100], B=[A/(A1)/T=1585504408436, B/(A1,B1)/T=1585504408591, A/(A2,B1)/T=1585504408695, A/(A3,B1)/T=1585504408849, B/(A3,B2)/T=1585504408965]}
29-3-20 17:53:29.133 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
29-3-20 17:53:29.133 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1585504408436
29-3-20 17:53:29.133 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A1,B1)/T=1585504408591
29-3-20 17:53:29.133 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2,B1)/T=1585504408695
29-3-20 17:53:29.133 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3,B1)/T=1585504408849
29-3-20 17:53:29.133 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A3,B2)/T=1585504408965
29-3-20 17:53:29.133 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A4,B2)/T=1585504409100
29-3-20 17:53:29.133 | DatabaseReconci | Test worker    | INFO : - Winner is A with branch: 
29-3-20 17:53:29.133 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1585504408436
29-3-20 17:53:29.133 | DatabaseReconci | Test worker    | INFO :   + B/(A1,B1)/T=1585504408591
29-3-20 17:53:29.133 | DatabaseReconci | Test worker    | INFO :   + A/(A2,B1)/T=1585504408695
29-3-20 17:53:29.133 | DatabaseReconci | Test worker    | INFO :   + A/(A3,B1)/T=1585504408849
29-3-20 17:53:29.133 | DatabaseReconci | Test worker    | INFO :   + B/(A3,B2)/T=1585504408965
29-3-20 17:53:29.133 | DatabaseReconci | Test worker    | INFO :   + A/(A4,B2)/T=1585504409100
29-3-20 17:53:29.133 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
29-3-20 17:53:29.134 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
29-3-20 17:53:29.134 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
29-3-20 17:53:29.134 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1585504408436, B/(A1,B1)/T=1585504408591, A/(A2,B1)/T=1585504408695, A/(A3,B1)/T=1585504408849, B/(A3,B2)/T=1585504408965]
29-3-20 17:53:29.134 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1585504408436, B/(A1,B1)/T=1585504408591, A/(A2,B1)/T=1585504408695, A/(A3,B1)/T=1585504408849, B/(A3,B2)/T=1585504408965, A/(A4,B2)/T=1585504409100]
29-3-20 17:53:29.134 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
29-3-20 17:53:29.134 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A4,B2)/T=1585504409100]
29-3-20 17:53:29.134 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
29-3-20 17:53:29.134 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-200329175039872-91297-client-B/.syncany/cache/database-A-0000000004 ...
29-3-20 17:53:29.135 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A4,B2)/T=1585504409100
29-3-20 17:53:29.135 | DownOperation   | Test worker    | INFO : Determine file system actions ...
29-3-20 17:53:29.135 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:29.138 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
29-3-20 17:53:29.138 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
29-3-20 17:53:29.138 | FileSystemActio | Test worker    | INFO :   + Comparing local version: FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:29.138 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=6, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:29 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:29.139 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = A-moved, but actual PATH = B-moved, for file B-moved
29-3-20 17:53:29.139 | FileSystemActio | Test worker    | INFO :      -> (12) Rename / Changed file attributes: Local file has different file attributes: local file = /tmp/syncanytest/syncany-200329175039872-91297-client-B/B-moved, local version = FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-], winning version = FileVersion [version=6, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:29 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:29.139 | FileSystemActio | Test worker    | INFO :      -> RenameFileSystemAction [file1=FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=6, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:29 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:29.141 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
29-3-20 17:53:29.141 | FileSystemActio | Test worker    | INFO :    Sorted actions:
29-3-20 17:53:29.141 | FileSystemActio | Test worker    | INFO :    + RenameFileSystemAction [file1=FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=6, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:29 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:29.141 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
29-3-20 17:53:29.141 | DownOperation   | Test worker    | FINE :    +  RenameFileSystemAction [file1=FileVersion [version=5, path=B-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:28 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-], file2=FileVersion [version=6, path=A-moved, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:53:28 UTC 2020, linkTarget=null, checksum=667fca1eab4ae9dcb59000e6d339cb71b01ea3d4, updated=Sun Mar 29 17:53:29 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:29.142 | FileSystemActio | Test worker    | INFO :      - (1) Renaming file /tmp/syncanytest/syncany-200329175039872-91297-client-B/B-moved to /tmp/syncanytest/syncany-200329175039872-91297-client-B/A-moved ...
29-3-20 17:53:29.142 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
29-3-20 17:53:29.142 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
29-3-20 17:53:29.142 | DownOperation   | Test worker    | INFO :   + Applying database version (A4,B2)
29-3-20 17:53:29.142 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A4,B2)/T=1585504409100, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:29.149 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1585504409125] ...
29-3-20 17:53:29.152 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1585504409125]
29-3-20 17:53:29.152 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:29.152 | Cache           | Test worker    | INFO : Cache size okay (54 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:29.152 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@57e2ff83) ...
29-3-20 17:53:29.152 | DownOperation   | Test worker    | INFO : Sync down done.
29-3-20 17:53:29.156 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-200329175039872-91297-client-A/A-moved, but actual PATH = tmp/syncanytest/syncany-200329175039872-91297-client-B/A-moved, for file tmp/syncanytest/syncany-200329175039872-91297-client-B/A-moved
29-3-20 17:53:29.161 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:29.161 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:29.191 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from chunk order by CHECKSUM asc
29-3-20 17:53:29.196 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select STATUS, LOCALTIME, CLIENT, VECTORCLOCK_SERIALIZED from databaseversion order by ID asc
29-3-20 17:53:29.197 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CLIENT, LOGICALTIME from databaseversion_vectorclock order by DATABASEVERSION_ID asc, CLIENT asc
29-3-20 17:53:29.197 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select CHECKSUM, SIZE from filecontent order by CHECKSUM asc
29-3-20 17:53:29.201 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILECONTENT_CHECKSUM, CHUNK_CHECKSUM, NUM from filecontent_chunk order by FILECONTENT_CHECKSUM asc, CHUNK_CHECKSUM asc, NUM asc
29-3-20 17:53:29.201 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID from filehistory order by ID asc, DATABASEVERSION_ID asc
29-3-20 17:53:29.202 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select FILEHISTORY_ID, VERSION, PATH, TYPE, STATUS, SIZE, LASTMODIFIED, LINKTARGET, FILECONTENT_CHECKSUM, UPDATED, POSIXPERMS, DOSATTRS from fileversion order by FILEHISTORY_ID asc, VERSION asc, DATABASEVERSION_ID asc
29-3-20 17:53:29.203 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select ID, SIZE from multichunk order by ID asc
29-3-20 17:53:29.203 | TestAssertUtil  | Test worker    | FINE :  Comparing database table: select MULTICHUNK_ID, CHUNK_CHECKSUM from multichunk_chunk order by MULTICHUNK_ID asc, CHUNK_CHECKSUM asc