Class org.syncany.tests.integration.scenarios.EvilCUpWithoutDownScenarioTest

1

tests

0

failures

0

ignored

0.681s

duration

100%

successful

Tests

Test Duration Result
testEvilC 0.681s passed

Standard error

29-3-20 17:52:31.773 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:31.773 | LocalTransferMa | Test worker    | INFO : testTargetExists: Target exists.
29-3-20 17:52:31.784 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:31.784 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-A' ...
29-3-20 17:52:31.784 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:31.785 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:31.785 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:31.785 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:31.785 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:31.785 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:31.785 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:31.785 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:31.785 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:31.785 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-A' ...
29-3-20 17:52:31.785 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:31.785 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:31.785 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:52:31.785 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:52:31.785 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:31.786 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:31.786 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:31.786 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:31.786 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:31.786 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:31.786 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:52:31.786 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:52:31.808 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
29-3-20 17:52:31.809 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
29-3-20 17:52:31.815 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
29-3-20 17:52:31.817 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
29-3-20 17:52:31.817 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
29-3-20 17:52:31.821 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
29-3-20 17:52:31.821 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
29-3-20 17:52:31.821 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
29-3-20 17:52:31.821 | 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:52:31.822 | 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:52:31.824 | 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:52:31.825 | 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:52:31.827 | 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:52:31.828 | 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:52:31.829 | 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:52:31.831 | 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:52:31.832 | 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:52:31.837 | 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:52:31.838 | 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:52:31.839 | 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:52:31.841 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
29-3-20 17:52:31.841 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
29-3-20 17:52:31.841 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
29-3-20 17:52:31.844 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
29-3-20 17:52:31.845 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
29-3-20 17:52:31.846 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
29-3-20 17:52:31.847 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
29-3-20 17:52:31.848 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
29-3-20 17:52:31.850 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
29-3-20 17:52:31.850 | 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:52:31.851 | 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:52:31.853 | 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:52:31.854 | 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:52:31.856 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
29-3-20 17:52:31.856 | 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:52:31.857 | 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:52:31.860 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
29-3-20 17:52:31.860 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
29-3-20 17:52:31.860 | 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:52:31.861 | UpOperation     | Test worker    | INFO : 
29-3-20 17:52:31.861 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
29-3-20 17:52:31.861 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:31.861 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@659181fc) ...
29-3-20 17:52:31.862 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:31.862 | StatusOperation | Test worker    | INFO : 
29-3-20 17:52:31.862 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-3-20 17:52:31.862 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:31.862 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
29-3-20 17:52:31.862 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:52:31.862 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@29036081) ...
29-3-20 17:52:31.863 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-21853-client-A ...
29-3-20 17:52:31.863 | StatusOperation | Test worker    | FINE : - New file: A1
29-3-20 17:52:31.863 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:52:31.863 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@74d1c3db) ...
29-3-20 17:52:31.863 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:52:31.864 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:31.864 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:52:31.864 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:52:31.864 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:31.864 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@72918ab8) ...
29-3-20 17:52:31.864 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:52:31.864 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@2c0053ee) ...
29-3-20 17:52:31.864 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-3-20 17:52:31.864 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1585504351786] ...
29-3-20 17:52:31.864 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1585504351786]
29-3-20 17:52:31.864 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1585504351786] ...
29-3-20 17:52:31.865 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:31.872 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-3-20 17:52:31.872 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-3-20 17:52:31.872 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@a77b1cf) ...
29-3-20 17:52:31.872 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-3-20 17:52:31.872 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-200329175039872-21853-client-A/A1
29-3-20 17:52:31.873 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-200329175039872-21853-client-A/A1
29-3-20 17:52:31.874 | Indexer         | AsyncI/syncany | FINE : - Chunk new: 403782c823a78e235302358812b38284f93c7a5b
29-3-20 17:52:31.875 | Indexer         | AsyncI/syncany | FINE : - +MultiChunk e86015ff10b2a1d6d489a0e11e0eab80be223c5c
29-3-20 17:52:31.875 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: 403782c823a78e235302358812b38284f93c7a5b > e86015ff10b2a1d6d489a0e11e0eab80be223c5c
29-3-20 17:52:31.875 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 403782c823a78e235302358812b38284f93c7a5b > /tmp/syncanytest/syncany-200329175039872-21853-client-A/A1
29-3-20 17:52:31.875 | Indexer         | AsyncI/syncany | FINE : - /File: A1 (checksum 403782c823a78e235302358812b38284f93c7a5b)
29-3-20 17:52:31.876 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: A1, checksum: 403782c823a78e235302358812b38284f93c7a5b)
29-3-20 17:52:31.876 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file A1
29-3-20 17:52:31.876 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=A1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=403782c823a78e235302358812b38284f93c7a5b, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:52:31.876 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
29-3-20 17:52:31.877 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@6eea568a) ...
29-3-20 17:52:31.877 | Indexer         | AsyncI/syncany | FINE : - /MultiChunk e86015ff10b2a1d6d489a0e11e0eab80be223c5c
29-3-20 17:52:31.877 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@6a8b1ac4) ...
29-3-20 17:52:31.877 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504351872, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-3-20 17:52:31.877 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@611ac418) ...
29-3-20 17:52:31.877 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-3-20 17:52:31.878 | UpOperation     | Test worker    | INFO : Last vector clock was: ()
29-3-20 17:52:31.878 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-3-20 17:52:31.878 | UpOperation     | Test worker    | INFO : - Uploading multichunk e86015ff10b2a1d6d489a0e11e0eab80be223c5c from /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/multichunk-e86015ff10b2a1d6d489a0e11e0eab80be223c5c to RemoteFile[name=multichunk-e86015ff10b2a1d6d489a0e11e0eab80be223c5c] ...
29-3-20 17:52:31.878 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/multichunk-e86015ff10b2a1d6d489a0e11e0eab80be223c5c -> Temp. remote file: RemoteFile[name=temp-dNakx-multichunk-e86015ff10b2a1d6d489a0e11e0eab80be223c5c], final location: RemoteFile[name=multichunk-e86015ff10b2a1d6d489a0e11e0eab80be223c5c]
29-3-20 17:52:31.878 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A1)/T=1585504351878, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-3-20 17:52:31.879 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A1)/T=1585504351878 to file /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-A-0000000001 ... 
29-3-20 17:52:31.879 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-A-0000000001 ...
29-3-20 17:52:31.879 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-3-20 17:52:31.879 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-A-0000000001 to RemoteFile[name=database-A-0000000001] ...
29-3-20 17:52:31.879 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-A-0000000001 -> Temp. remote file: RemoteFile[name=temp-fJWda-database-A-0000000001], final location: RemoteFile[name=database-A-0000000001]
29-3-20 17:52:31.879 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-3-20 17:52:31.879 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-3-20 17:52:31.882 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/temp-transaction-16385011482542622903.tmp
29-3-20 17:52:31.882 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@76f8fb40) ...
29-3-20 17:52:31.882 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-5604c1ad] ...
29-3-20 17:52:31.883 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-3-20 17:52:31.883 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@2d417ba3) ...
29-3-20 17:52:31.883 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/multichunk-e86015ff10b2a1d6d489a0e11e0eab80be223c5c to temp. file RemoteFile[name=temp-dNakx-multichunk-e86015ff10b2a1d6d489a0e11e0eab80be223c5c] ...
29-3-20 17:52:31.883 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-3-20 17:52:31.884 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@52b9a587) ...
29-3-20 17:52:31.884 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-A-0000000001 to temp. file RemoteFile[name=temp-fJWda-database-A-0000000001] ...
29-3-20 17:52:31.884 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-dNakx-multichunk-e86015ff10b2a1d6d489a0e11e0eab80be223c5c] to final location RemoteFile[name=multichunk-e86015ff10b2a1d6d489a0e11e0eab80be223c5c] ...
29-3-20 17:52:31.884 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-fJWda-database-A-0000000001] to final location RemoteFile[name=database-A-0000000001] ...
29-3-20 17:52:31.885 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-5604c1ad] ...
29-3-20 17:52:31.885 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-3-20 17:52:31.885 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-3-20 17:52:31.885 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A1)/T=1585504351878) ...
29-3-20 17:52:31.886 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-3-20 17:52:31.899 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A1)/T=1585504351878, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-3-20 17:52:31.899 | UpOperation     | Test worker    | INFO : Committing local database.
29-3-20 17:52:31.899 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-3-20 17:52:31.899 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504351883, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-3-20 17:52:31.899 | UpOperation     | Test worker    | INFO : Sync up done.
29-3-20 17:52:31.901 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1585504351786] ...
29-3-20 17:52:31.908 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1585504351786]
29-3-20 17:52:31.908 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:52:31.908 | Cache           | Test worker    | INFO : Cache size okay (51 KB), no need to clean (keep size is 500 MB)
29-3-20 17:52:31.908 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@ba8bba5) ...
29-3-20 17:52:31.908 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:31.908 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-A' ...
29-3-20 17:52:31.908 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:31.908 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:31.909 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:31.909 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:31.909 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:31.909 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:31.909 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:31.909 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:31.909 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:31.909 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-A' ...
29-3-20 17:52:31.909 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:31.909 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:31.909 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:52:31.909 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:52:31.909 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:31.909 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:31.909 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:31.909 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:31.909 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:31.909 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:31.909 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:52:31.909 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:52:31.911 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:31.911 | UpOperation     | Test worker    | INFO : 
29-3-20 17:52:31.911 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
29-3-20 17:52:31.911 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:31.911 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@46139f11) ...
29-3-20 17:52:31.911 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:31.911 | StatusOperation | Test worker    | INFO : 
29-3-20 17:52:31.911 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-3-20 17:52:31.911 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:31.911 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
29-3-20 17:52:31.911 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:52:31.912 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@46a2272b) ...
29-3-20 17:52:31.912 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-21853-client-A ...
29-3-20 17:52:31.912 | StatusOperation | Test worker    | FINE : - New file: A2
29-3-20 17:52:31.912 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:52:31.912 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@36001438) ...
29-3-20 17:52:31.913 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:52:31.913 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:31.913 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:52:31.913 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:52:31.913 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:31.913 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@ca01efd) ...
29-3-20 17:52:31.913 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:52:31.913 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:52:31.913 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@69b3a0c) ...
29-3-20 17:52:31.913 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-3-20 17:52:31.913 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1585504351909] ...
29-3-20 17:52:31.913 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1585504351909]
29-3-20 17:52:31.914 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1585504351909] ...
29-3-20 17:52:31.914 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:31.916 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-3-20 17:52:31.921 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-3-20 17:52:31.921 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@330b33c0) ...
29-3-20 17:52:31.921 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-3-20 17:52:31.922 | Indexer         | AsyncI/syncany | FINE :   + Deleted: Adding DELETED version: FileVersion [version=2, path=A1, type=FILE, status=DELETED, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=403782c823a78e235302358812b38284f93c7a5b, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:52:31.922 | Indexer         | AsyncI/syncany | FINE :                            based on: FileVersion [version=1, path=A1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=403782c823a78e235302358812b38284f93c7a5b, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:52:31.922 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-200329175039872-21853-client-A/A2
29-3-20 17:52:31.922 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-200329175039872-21853-client-A/A2
29-3-20 17:52:31.923 | Indexer         | AsyncI/syncany | FINE : - Chunk exists: 403782c823a78e235302358812b38284f93c7a5b
29-3-20 17:52:31.923 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 403782c823a78e235302358812b38284f93c7a5b > /tmp/syncanytest/syncany-200329175039872-21853-client-A/A2
29-3-20 17:52:31.923 | Indexer         | AsyncI/syncany | FINE : - /File: A2 (checksum 403782c823a78e235302358812b38284f93c7a5b)
29-3-20 17:52:31.924 | Indexer         | AsyncI/syncany | FINE :    * Found old file history 06496060b9efddc95029199ff390f87fc1b15909 (by checksum: 403782c823a78e235302358812b38284f93c7a5b), appending new version.
29-3-20 17:52:31.924 | FileVersionComp | AsyncI/syncany | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = A2, but actual PATH = A1, for file A1
29-3-20 17:52:31.924 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=2, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=403782c823a78e235302358812b38284f93c7a5b, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:52:31.924 | Indexer         | AsyncI/syncany | INFO :      based on file version: FileVersion [version=1, path=A1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=403782c823a78e235302358812b38284f93c7a5b, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:52:31.924 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@6d26f7ec) ...
29-3-20 17:52:31.925 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@3f4ede3d) ...
29-3-20 17:52:31.925 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504351921, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:52:31.925 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-3-20 17:52:31.925 | UpOperation     | Test worker    | INFO : Last vector clock was: (A1)
29-3-20 17:52:31.925 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-3-20 17:52:31.926 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A2)/T=1585504351925, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:52:31.926 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A2)/T=1585504351925 to file /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-A-0000000002 ... 
29-3-20 17:52:31.926 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-A-0000000002 ...
29-3-20 17:52:31.926 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-3-20 17:52:31.926 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-A-0000000002 to RemoteFile[name=database-A-0000000002] ...
29-3-20 17:52:31.926 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-A-0000000002 -> Temp. remote file: RemoteFile[name=temp-pVtyT-database-A-0000000002], final location: RemoteFile[name=database-A-0000000002]
29-3-20 17:52:31.927 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-3-20 17:52:31.927 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-3-20 17:52:31.927 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/temp-transaction-4281298122218645248.tmp
29-3-20 17:52:31.927 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@5c3fcdd4) ...
29-3-20 17:52:31.928 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-3b56af07] ...
29-3-20 17:52:31.928 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-3-20 17:52:31.928 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@1a05aafc) ...
29-3-20 17:52:31.928 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-A-0000000002 to temp. file RemoteFile[name=temp-pVtyT-database-A-0000000002] ...
29-3-20 17:52:31.928 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-pVtyT-database-A-0000000002] to final location RemoteFile[name=database-A-0000000002] ...
29-3-20 17:52:31.928 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-3b56af07] ...
29-3-20 17:52:31.928 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-3-20 17:52:31.928 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-3-20 17:52:31.928 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A2)/T=1585504351925) ...
29-3-20 17:52:31.929 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-3-20 17:52:31.931 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@1e153989) ...
29-3-20 17:52:31.932 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A2)/T=1585504351925, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:52:31.932 | UpOperation     | Test worker    | INFO : Committing local database.
29-3-20 17:52:31.933 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-3-20 17:52:31.934 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-3-20 17:52:31.935 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504351934, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-3-20 17:52:31.935 | UpOperation     | Test worker    | INFO : Sync up done.
29-3-20 17:52:31.936 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1585504351909] ...
29-3-20 17:52:31.936 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1585504351909]
29-3-20 17:52:31.936 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:52:31.937 | Cache           | Test worker    | INFO : Cache size okay (52 KB), no need to clean (keep size is 500 MB)
29-3-20 17:52:31.937 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@4d107ee3) ...
29-3-20 17:52:31.937 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:31.937 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-A' ...
29-3-20 17:52:31.937 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:31.937 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:31.937 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:31.937 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:31.937 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:31.937 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:31.937 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:31.937 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:31.937 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:31.938 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-A' ...
29-3-20 17:52:31.938 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:31.938 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:31.938 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:52:31.938 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:52:31.938 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:31.938 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:31.938 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:31.938 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:31.938 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:31.938 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:31.938 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:52:31.938 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:52:31.938 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:31.939 | UpOperation     | Test worker    | INFO : 
29-3-20 17:52:31.939 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
29-3-20 17:52:31.939 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:31.939 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@6a77df9f) ...
29-3-20 17:52:31.939 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:31.939 | StatusOperation | Test worker    | INFO : 
29-3-20 17:52:31.939 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-3-20 17:52:31.939 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:31.939 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
29-3-20 17:52:31.939 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:52:31.939 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@f0c786d) ...
29-3-20 17:52:31.940 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-21853-client-A ...
29-3-20 17:52:31.940 | StatusOperation | Test worker    | FINE : - New file: A3
29-3-20 17:52:31.941 | FileVersionComp | Test worker    | INFO :      - [CHANGED_CHECKSUM]: Local file DIFFERS from file version, expected CHECKSUM = 403782c823a78e235302358812b38284f93c7a5b, but actual CHECKSUM = 8e1961d4a5e0b420cdcf5ecd2293f364212eb454, for file A2
29-3-20 17:52:31.941 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:52:31.941 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@1f965b55) ...
29-3-20 17:52:31.941 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:52:31.942 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:31.942 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:52:31.942 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:52:31.942 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:31.942 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@6e116094) ...
29-3-20 17:52:31.942 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:52:31.942 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-3-20 17:52:31.942 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:52:31.942 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@1eb88224) ...
29-3-20 17:52:31.942 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-3-20 17:52:31.942 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1585504351938] ...
29-3-20 17:52:31.942 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1585504351938]
29-3-20 17:52:31.942 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1585504351938] ...
29-3-20 17:52:31.943 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:31.943 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-3-20 17:52:31.943 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-3-20 17:52:31.943 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@59dfbb6e) ...
29-3-20 17:52:31.943 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-3-20 17:52:31.943 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-200329175039872-21853-client-A/A3
29-3-20 17:52:31.944 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-200329175039872-21853-client-A/A3
29-3-20 17:52:31.944 | Indexer         | AsyncI/syncany | FINE : - Chunk new: 474def2a9811b6928ec7d88632e2a7be551a2ed5
29-3-20 17:52:31.945 | Indexer         | AsyncI/syncany | FINE : - +MultiChunk 90b412e08871e882fe6fa8ce9352a727345a9545
29-3-20 17:52:31.945 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: 474def2a9811b6928ec7d88632e2a7be551a2ed5 > 90b412e08871e882fe6fa8ce9352a727345a9545
29-3-20 17:52:31.945 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 474def2a9811b6928ec7d88632e2a7be551a2ed5 > /tmp/syncanytest/syncany-200329175039872-21853-client-A/A3
29-3-20 17:52:31.945 | Indexer         | AsyncI/syncany | FINE : - /File: A3 (checksum 474def2a9811b6928ec7d88632e2a7be551a2ed5)
29-3-20 17:52:31.946 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: A3, checksum: 474def2a9811b6928ec7d88632e2a7be551a2ed5)
29-3-20 17:52:31.946 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file A3
29-3-20 17:52:31.946 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=A3, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=474def2a9811b6928ec7d88632e2a7be551a2ed5, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:52:31.946 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
29-3-20 17:52:31.946 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@4a725b4e) ...
29-3-20 17:52:31.946 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-200329175039872-21853-client-A/A2
29-3-20 17:52:31.946 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-200329175039872-21853-client-A/A2
29-3-20 17:52:31.948 | Indexer         | AsyncI/syncany | FINE : - Chunk new: 8e1961d4a5e0b420cdcf5ecd2293f364212eb454
29-3-20 17:52:31.948 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: 8e1961d4a5e0b420cdcf5ecd2293f364212eb454 > 90b412e08871e882fe6fa8ce9352a727345a9545
29-3-20 17:52:31.948 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 8e1961d4a5e0b420cdcf5ecd2293f364212eb454 > /tmp/syncanytest/syncany-200329175039872-21853-client-A/A2
29-3-20 17:52:31.948 | Indexer         | AsyncI/syncany | FINE : - /File: A2 (checksum 8e1961d4a5e0b420cdcf5ecd2293f364212eb454)
29-3-20 17:52:31.949 | Indexer         | AsyncI/syncany | FINE :    * Found old file history 06496060b9efddc95029199ff390f87fc1b15909 (by path: A2), appending new version.
29-3-20 17:52:31.949 | FileVersionComp | AsyncI/syncany | INFO :      - [CHANGED_CHECKSUM]: Local file DIFFERS from file version, expected CHECKSUM = 8e1961d4a5e0b420cdcf5ecd2293f364212eb454, but actual CHECKSUM = 403782c823a78e235302358812b38284f93c7a5b, for file A2
29-3-20 17:52:31.949 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=8e1961d4a5e0b420cdcf5ecd2293f364212eb454, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:52:31.949 | Indexer         | AsyncI/syncany | INFO :      based on file version: FileVersion [version=2, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=403782c823a78e235302358812b38284f93c7a5b, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:52:31.949 | Indexer         | AsyncI/syncany | FINE : - /MultiChunk 90b412e08871e882fe6fa8ce9352a727345a9545
29-3-20 17:52:31.950 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@37f38556) ...
29-3-20 17:52:31.950 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504351943, chunks=2, multiChunks=1, fileContents=2, fileHistories=2]
29-3-20 17:52:31.950 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-3-20 17:52:31.950 | UpOperation     | Test worker    | INFO : Last vector clock was: (A2)
29-3-20 17:52:31.950 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-3-20 17:52:31.951 | UpOperation     | Test worker    | INFO : - Uploading multichunk 90b412e08871e882fe6fa8ce9352a727345a9545 from /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/multichunk-90b412e08871e882fe6fa8ce9352a727345a9545 to RemoteFile[name=multichunk-90b412e08871e882fe6fa8ce9352a727345a9545] ...
29-3-20 17:52:31.951 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/multichunk-90b412e08871e882fe6fa8ce9352a727345a9545 -> Temp. remote file: RemoteFile[name=temp-USWAw-multichunk-90b412e08871e882fe6fa8ce9352a727345a9545], final location: RemoteFile[name=multichunk-90b412e08871e882fe6fa8ce9352a727345a9545]
29-3-20 17:52:31.951 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A3)/T=1585504351950, chunks=2, multiChunks=1, fileContents=2, fileHistories=2]
29-3-20 17:52:31.951 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A3)/T=1585504351950 to file /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-A-0000000003 ... 
29-3-20 17:52:31.951 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-A-0000000003 ...
29-3-20 17:52:31.951 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-3-20 17:52:31.951 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-A-0000000003 to RemoteFile[name=database-A-0000000003] ...
29-3-20 17:52:31.952 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-A-0000000003 -> Temp. remote file: RemoteFile[name=temp-KMsBW-database-A-0000000003], final location: RemoteFile[name=database-A-0000000003]
29-3-20 17:52:31.952 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-3-20 17:52:31.952 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-3-20 17:52:31.953 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/temp-transaction-8867713728876234644.tmp
29-3-20 17:52:31.953 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@7059cb38) ...
29-3-20 17:52:31.953 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-44a6bfc0] ...
29-3-20 17:52:31.953 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-3-20 17:52:31.954 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@7263bb75) ...
29-3-20 17:52:31.954 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/multichunk-90b412e08871e882fe6fa8ce9352a727345a9545 to temp. file RemoteFile[name=temp-USWAw-multichunk-90b412e08871e882fe6fa8ce9352a727345a9545] ...
29-3-20 17:52:31.954 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@51e4ac4b) ...
29-3-20 17:52:31.954 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-A-0000000003 to temp. file RemoteFile[name=temp-KMsBW-database-A-0000000003] ...
29-3-20 17:52:31.954 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-USWAw-multichunk-90b412e08871e882fe6fa8ce9352a727345a9545] to final location RemoteFile[name=multichunk-90b412e08871e882fe6fa8ce9352a727345a9545] ...
29-3-20 17:52:31.954 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-KMsBW-database-A-0000000003] to final location RemoteFile[name=database-A-0000000003] ...
29-3-20 17:52:31.954 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-44a6bfc0] ...
29-3-20 17:52:31.955 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-3-20 17:52:31.955 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-3-20 17:52:31.955 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A3)/T=1585504351950) ...
29-3-20 17:52:31.957 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-3-20 17:52:31.959 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@1cf81f62) ...
29-3-20 17:52:31.962 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-3-20 17:52:31.962 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A3)/T=1585504351950, chunks=2, multiChunks=1, fileContents=2, fileHistories=2]
29-3-20 17:52:31.962 | UpOperation     | Test worker    | INFO : Committing local database.
29-3-20 17:52:31.962 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-3-20 17:52:31.962 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504351962, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-3-20 17:52:31.962 | UpOperation     | Test worker    | INFO : Sync up done.
29-3-20 17:52:31.963 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1585504351938] ...
29-3-20 17:52:31.964 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1585504351938]
29-3-20 17:52:31.964 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:52:31.964 | Cache           | Test worker    | INFO : Cache size okay (154 KB), no need to clean (keep size is 500 MB)
29-3-20 17:52:31.964 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@574c7668) ...
29-3-20 17:52:31.964 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:31.964 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-A' ...
29-3-20 17:52:31.964 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:31.964 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:31.964 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:31.964 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:31.964 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:31.964 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:31.964 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:31.964 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:31.964 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:31.965 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-A' ...
29-3-20 17:52:31.965 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:31.965 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:31.965 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:52:31.965 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:52:31.965 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:31.965 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:31.965 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:31.965 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:31.965 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:31.965 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:31.965 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:52:31.965 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:52:31.968 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:31.968 | UpOperation     | Test worker    | INFO : 
29-3-20 17:52:31.968 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
29-3-20 17:52:31.968 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:31.968 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@25b1fdb9) ...
29-3-20 17:52:31.969 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:31.969 | StatusOperation | Test worker    | INFO : 
29-3-20 17:52:31.969 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-3-20 17:52:31.969 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:31.969 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
29-3-20 17:52:31.969 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:52:31.969 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@2207e784) ...
29-3-20 17:52:31.970 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-21853-client-A ...
29-3-20 17:52:31.971 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:52:31.971 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@1f0f26e4) ...
29-3-20 17:52:31.971 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:52:31.972 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:31.972 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:52:31.972 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:52:31.972 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:31.972 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@83af3fd) ...
29-3-20 17:52:31.972 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:52:31.972 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-3-20 17:52:31.972 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
29-3-20 17:52:31.972 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:52:31.972 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@79149160) ...
29-3-20 17:52:31.972 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-3-20 17:52:31.972 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1585504351965] ...
29-3-20 17:52:31.972 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1585504351965]
29-3-20 17:52:31.972 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1585504351965] ...
29-3-20 17:52:31.973 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:31.973 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-3-20 17:52:31.973 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-3-20 17:52:31.973 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-3-20 17:52:31.974 | Indexer         | AsyncI/syncany | FINE :   + Deleted: Adding DELETED version: FileVersion [version=2, path=A3, type=FILE, status=DELETED, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=474def2a9811b6928ec7d88632e2a7be551a2ed5, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:52:31.974 | Indexer         | AsyncI/syncany | FINE :                            based on: FileVersion [version=1, path=A3, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=474def2a9811b6928ec7d88632e2a7be551a2ed5, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:52:31.974 | Indexer         | AsyncI/syncany | FINE : Added database version with only deletions: DatabaseVersion [header=UnknownMachine/()/T=1585504351973, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:52:31.974 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-3-20 17:52:31.975 | UpOperation     | Test worker    | INFO : Last vector clock was: (A3)
29-3-20 17:52:31.975 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-3-20 17:52:31.975 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A4)/T=1585504351975, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:52:31.976 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A4)/T=1585504351975 to file /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-A-0000000004 ... 
29-3-20 17:52:31.976 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-A-0000000004 ...
29-3-20 17:52:31.979 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-3-20 17:52:31.979 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-A-0000000004 to RemoteFile[name=database-A-0000000004] ...
29-3-20 17:52:31.979 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-A-0000000004 -> Temp. remote file: RemoteFile[name=temp-xJGqZ-database-A-0000000004], final location: RemoteFile[name=database-A-0000000004]
29-3-20 17:52:31.979 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-3-20 17:52:31.979 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-3-20 17:52:31.980 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/temp-transaction-581655232779782708.tmp
29-3-20 17:52:31.980 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@25f05c37) ...
29-3-20 17:52:31.980 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-5c64f656] ...
29-3-20 17:52:31.980 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-3-20 17:52:31.981 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@1a9a54c4) ...
29-3-20 17:52:31.981 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-A-0000000004 to temp. file RemoteFile[name=temp-xJGqZ-database-A-0000000004] ...
29-3-20 17:52:31.981 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-xJGqZ-database-A-0000000004] to final location RemoteFile[name=database-A-0000000004] ...
29-3-20 17:52:31.981 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-5c64f656] ...
29-3-20 17:52:31.981 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-3-20 17:52:31.981 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-3-20 17:52:31.981 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A4)/T=1585504351975) ...
29-3-20 17:52:31.982 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-3-20 17:52:31.985 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A4)/T=1585504351975, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:52:31.985 | UpOperation     | Test worker    | INFO : Committing local database.
29-3-20 17:52:31.985 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-3-20 17:52:31.986 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-3-20 17:52:31.987 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504351986, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-3-20 17:52:31.987 | UpOperation     | Test worker    | INFO : Sync up done.
29-3-20 17:52:31.988 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1585504351965] ...
29-3-20 17:52:31.992 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1585504351965]
29-3-20 17:52:31.992 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:52:31.992 | Cache           | Test worker    | INFO : Cache size okay (155 KB), no need to clean (keep size is 500 MB)
29-3-20 17:52:31.992 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@54416fea) ...
29-3-20 17:52:31.992 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:31.992 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-B' ...
29-3-20 17:52:31.992 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:31.992 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:31.992 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:31.992 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:31.992 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:31.992 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:31.992 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:31.992 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:31.993 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:31.993 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-B' ...
29-3-20 17:52:31.993 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:31.993 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:31.993 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:52:31.993 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:52:31.993 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:31.993 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:31.993 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:31.993 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:31.993 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:31.993 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:31.993 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:52:31.993 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:52:32.004 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
29-3-20 17:52:32.004 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
29-3-20 17:52:32.009 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
29-3-20 17:52:32.011 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
29-3-20 17:52:32.011 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
29-3-20 17:52:32.014 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
29-3-20 17:52:32.014 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
29-3-20 17:52:32.015 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
29-3-20 17:52:32.015 | 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:52:32.016 | 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:52:32.018 | 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:52:32.019 | 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:52:32.021 | 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:52:32.022 | 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:52:32.024 | 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:52:32.025 | 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:52:32.027 | 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:52:32.028 | 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:52:32.030 | 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:52:32.031 | 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:52:32.032 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
29-3-20 17:52:32.033 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
29-3-20 17:52:32.033 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
29-3-20 17:52:32.035 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
29-3-20 17:52:32.036 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
29-3-20 17:52:32.037 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
29-3-20 17:52:32.039 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
29-3-20 17:52:32.040 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
29-3-20 17:52:32.041 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
29-3-20 17:52:32.041 | 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:52:32.043 | 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:52:32.044 | 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:52:32.046 | 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:52:32.048 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
29-3-20 17:52:32.048 | 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:52:32.050 | 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:52:32.051 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
29-3-20 17:52:32.051 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
29-3-20 17:52:32.051 | 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:52:32.053 | DownOperation   | Test worker    | INFO : 
29-3-20 17:52:32.053 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
29-3-20 17:52:32.053 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.053 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@381f8118) ...
29-3-20 17:52:32.053 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:52:32.054 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.054 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:52:32.054 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
29-3-20 17:52:32.054 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.054 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@336a0900) ...
29-3-20 17:52:32.054 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:52:32.054 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is new.
29-3-20 17:52:32.054 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
29-3-20 17:52:32.054 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is new.
29-3-20 17:52:32.054 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
29-3-20 17:52:32.054 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@30bd7bfc) ...
29-3-20 17:52:32.054 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@25cba410) ...
29-3-20 17:52:32.054 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1585504351993] ...
29-3-20 17:52:32.055 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1585504351993]
29-3-20 17:52:32.055 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1585504351993] ...
29-3-20 17:52:32.055 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
29-3-20 17:52:32.055 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000004 to local cache at /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/database-A-0000000004
29-3-20 17:52:32.055 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@18c1f6b2) ...
29-3-20 17:52:32.055 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000002 to local cache at /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/database-A-0000000002
29-3-20 17:52:32.056 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@60d22a9e) ...
29-3-20 17:52:32.056 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000003 to local cache at /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/database-A-0000000003
29-3-20 17:52:32.056 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@72176abf) ...
29-3-20 17:52:32.056 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000001 to local cache at /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/database-A-0000000001
29-3-20 17:52:32.056 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@71516610) ...
29-3-20 17:52:32.057 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
29-3-20 17:52:32.057 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/database-A-0000000001 ...
29-3-20 17:52:32.062 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1585504351878
29-3-20 17:52:32.062 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/database-A-0000000002 ...
29-3-20 17:52:32.063 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1585504351925
29-3-20 17:52:32.064 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/database-A-0000000003 ...
29-3-20 17:52:32.065 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A3)/T=1585504351950
29-3-20 17:52:32.065 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/database-A-0000000004 ...
29-3-20 17:52:32.066 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A4)/T=1585504351975
29-3-20 17:52:32.066 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.066 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.066 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.066 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.066 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
29-3-20 17:52:32.067 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1585504351878, A/(A2)/T=1585504351925, A/(A3)/T=1585504351950, A/(A4)/T=1585504351975], B=[]}
29-3-20 17:52:32.067 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
29-3-20 17:52:32.067 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1585504351878
29-3-20 17:52:32.067 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1585504351925
29-3-20 17:52:32.067 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3)/T=1585504351950
29-3-20 17:52:32.067 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A4)/T=1585504351975
29-3-20 17:52:32.067 | DatabaseReconci | Test worker    | INFO : - Winner is A with branch: 
29-3-20 17:52:32.067 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1585504351878
29-3-20 17:52:32.067 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1585504351925
29-3-20 17:52:32.067 | DatabaseReconci | Test worker    | INFO :   + A/(A3)/T=1585504351950
29-3-20 17:52:32.067 | DatabaseReconci | Test worker    | INFO :   + A/(A4)/T=1585504351975
29-3-20 17:52:32.067 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
29-3-20 17:52:32.067 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
29-3-20 17:52:32.067 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
29-3-20 17:52:32.067 | DatabaseReconci | Test worker    | INFO : Losers Branch: []
29-3-20 17:52:32.067 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1585504351878, A/(A2)/T=1585504351925, A/(A3)/T=1585504351950, A/(A4)/T=1585504351975]
29-3-20 17:52:32.067 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
29-3-20 17:52:32.067 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A1)/T=1585504351878, A/(A2)/T=1585504351925, A/(A3)/T=1585504351950, A/(A4)/T=1585504351975]
29-3-20 17:52:32.067 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
29-3-20 17:52:32.067 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/database-A-0000000001 ...
29-3-20 17:52:32.068 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1585504351878
29-3-20 17:52:32.068 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/database-A-0000000002 ...
29-3-20 17:52:32.069 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1585504351925
29-3-20 17:52:32.069 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/database-A-0000000003 ...
29-3-20 17:52:32.070 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A3)/T=1585504351950
29-3-20 17:52:32.070 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/database-A-0000000004 ...
29-3-20 17:52:32.071 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A4)/T=1585504351975
29-3-20 17:52:32.071 | DownOperation   | Test worker    | INFO : Determine file system actions ...
29-3-20 17:52:32.072 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.072 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
29-3-20 17:52:32.072 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
29-3-20 17:52:32.072 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
29-3-20 17:52:32.072 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=2, path=A3, type=FILE, status=DELETED, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=474def2a9811b6928ec7d88632e2a7be551a2ed5, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:52:32.073 | FileVersionComp | Test worker    | INFO :      - []: Local file does not exist, and expected file was deleted, for file A3
29-3-20 17:52:32.073 | FileSystemActio | Test worker    | INFO :      -> (1) Equals: Nothing to do, winning version equals winning file: FileVersion [version=2, path=A3, type=FILE, status=DELETED, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=474def2a9811b6928ec7d88632e2a7be551a2ed5, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-200329175039872-21853-client-B/A3
29-3-20 17:52:32.073 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
29-3-20 17:52:32.073 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=8e1961d4a5e0b420cdcf5ecd2293f364212eb454, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:52:32.073 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file A2
29-3-20 17:52:32.073 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=8e1961d4a5e0b420cdcf5ecd2293f364212eb454, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-200329175039872-21853-client-B/A2
29-3-20 17:52:32.073 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=8e1961d4a5e0b420cdcf5ecd2293f364212eb454, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:52:32.074 | DownOperation   | Test worker    | INFO :   + Adding multichunk 90b412e08871e882fe6fa8ce9352a727345a9545 to download list ...
29-3-20 17:52:32.074 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
29-3-20 17:52:32.074 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@5a52cebd) ...
29-3-20 17:52:32.074 | Downloader      | Test worker    | INFO :   + Downloading multichunk 90b412e08871e882fe6fa8ce9352a727345a9545 ...
29-3-20 17:52:32.074 | Downloader      | Test worker    | INFO :   + Decrypting multichunk 90b412e08871e882fe6fa8ce9352a727345a9545 ...
29-3-20 17:52:32.074 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk 90b412e08871e882fe6fa8ce9352a727345a9545 ...
29-3-20 17:52:32.075 | FileSystemActio | Test worker    | INFO :    Sorted actions:
29-3-20 17:52:32.075 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=8e1961d4a5e0b420cdcf5ecd2293f364212eb454, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:52:32.075 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
29-3-20 17:52:32.075 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=8e1961d4a5e0b420cdcf5ecd2293f364212eb454, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:52:32.075 | Assembler       | Test worker    | INFO :      - Creating file A2 to /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/temp-reconstructedFileVersion-5529216307390438502.tmp ...
29-3-20 17:52:32.076 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
29-3-20 17:52:32.076 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
29-3-20 17:52:32.076 | DownOperation   | Test worker    | INFO :   + Applying database version (A1)
29-3-20 17:52:32.076 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A1)/T=1585504351878, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-3-20 17:52:32.078 | DownOperation   | Test worker    | INFO :   + Applying database version (A2)
29-3-20 17:52:32.078 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A2)/T=1585504351925, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:52:32.078 | DownOperation   | Test worker    | INFO :   + Applying database version (A3)
29-3-20 17:52:32.078 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A3)/T=1585504351950, chunks=2, multiChunks=1, fileContents=2, fileHistories=2]
29-3-20 17:52:32.081 | DownOperation   | Test worker    | INFO :   + Applying database version (A4)
29-3-20 17:52:32.081 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A4)/T=1585504351975, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:52:32.084 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1585504351993] ...
29-3-20 17:52:32.085 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1585504351993]
29-3-20 17:52:32.085 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:52:32.085 | Cache           | Test worker    | INFO : Cache size okay (104 KB), no need to clean (keep size is 500 MB)
29-3-20 17:52:32.085 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@5de12e15) ...
29-3-20 17:52:32.085 | DownOperation   | Test worker    | INFO : Sync down done.
29-3-20 17:52:32.088 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-200329175039872-21853-client-A/A2, but actual PATH = tmp/syncanytest/syncany-200329175039872-21853-client-B/A2, for file tmp/syncanytest/syncany-200329175039872-21853-client-B/A2
29-3-20 17:52:32.089 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.089 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-B' ...
29-3-20 17:52:32.089 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.089 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.089 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.089 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.089 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.089 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.089 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.089 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.089 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.089 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-B' ...
29-3-20 17:52:32.089 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.089 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.089 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:52:32.089 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:52:32.090 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.090 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.090 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.090 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.090 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.090 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.090 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:52:32.090 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:52:32.090 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.090 | UpOperation     | Test worker    | INFO : 
29-3-20 17:52:32.090 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client B ...
29-3-20 17:52:32.090 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.090 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@341070c9) ...
29-3-20 17:52:32.091 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.091 | StatusOperation | Test worker    | INFO : 
29-3-20 17:52:32.091 | StatusOperation | Test worker    | INFO : Running 'Status' at client B ...
29-3-20 17:52:32.091 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.091 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:52:32.091 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@692a2492) ...
29-3-20 17:52:32.092 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-21853-client-B ...
29-3-20 17:52:32.092 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:52:32.092 | StatusOperation | Test worker    | FINE : - New file: A4,B1
29-3-20 17:52:32.092 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@44dbb946) ...
29-3-20 17:52:32.092 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:52:32.093 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.093 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:52:32.093 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
29-3-20 17:52:32.093 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.093 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@7cec9455) ...
29-3-20 17:52:32.093 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:52:32.093 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
29-3-20 17:52:32.093 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-3-20 17:52:32.093 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
29-3-20 17:52:32.093 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:52:32.093 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@68f4d709) ...
29-3-20 17:52:32.093 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-3-20 17:52:32.093 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-B-1585504352090] ...
29-3-20 17:52:32.093 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-B-1585504352090]
29-3-20 17:52:32.094 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-B-1585504352090] ...
29-3-20 17:52:32.098 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.099 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-3-20 17:52:32.133 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-3-20 17:52:32.134 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@7ada9111) ...
29-3-20 17:52:32.134 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-3-20 17:52:32.134 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-200329175039872-21853-client-B/A4,B1
29-3-20 17:52:32.134 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-200329175039872-21853-client-B/A4,B1
29-3-20 17:52:32.139 | Indexer         | AsyncI/syncany | FINE : - Chunk new: e555670dcd160e0370544dfcabb1ad489eac7cd2
29-3-20 17:52:32.139 | Indexer         | AsyncI/syncany | FINE : - +MultiChunk 620d8153735fb2cfb98e88ddc80a453759dc4fd9
29-3-20 17:52:32.142 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: e555670dcd160e0370544dfcabb1ad489eac7cd2 > 620d8153735fb2cfb98e88ddc80a453759dc4fd9
29-3-20 17:52:32.142 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: e555670dcd160e0370544dfcabb1ad489eac7cd2 > /tmp/syncanytest/syncany-200329175039872-21853-client-B/A4,B1
29-3-20 17:52:32.142 | Indexer         | AsyncI/syncany | FINE : - /File: A4,B1 (checksum e555670dcd160e0370544dfcabb1ad489eac7cd2)
29-3-20 17:52:32.143 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: A4,B1, checksum: e555670dcd160e0370544dfcabb1ad489eac7cd2)
29-3-20 17:52:32.144 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file A4,B1
29-3-20 17:52:32.144 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:32 UTC 2020, linkTarget=null, checksum=e555670dcd160e0370544dfcabb1ad489eac7cd2, updated=Sun Mar 29 17:52:32 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:52:32.144 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
29-3-20 17:52:32.144 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@6defb2b9) ...
29-3-20 17:52:32.144 | Indexer         | AsyncI/syncany | FINE : - /MultiChunk 620d8153735fb2cfb98e88ddc80a453759dc4fd9
29-3-20 17:52:32.144 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@36a7c3d) ...
29-3-20 17:52:32.144 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504352133, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-3-20 17:52:32.145 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-3-20 17:52:32.145 | UpOperation     | Test worker    | INFO : Last vector clock was: (A4)
29-3-20 17:52:32.145 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-3-20 17:52:32.146 | UpOperation     | Test worker    | INFO : - Uploading multichunk 620d8153735fb2cfb98e88ddc80a453759dc4fd9 from /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/multichunk-620d8153735fb2cfb98e88ddc80a453759dc4fd9 to RemoteFile[name=multichunk-620d8153735fb2cfb98e88ddc80a453759dc4fd9] ...
29-3-20 17:52:32.146 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/multichunk-620d8153735fb2cfb98e88ddc80a453759dc4fd9 -> Temp. remote file: RemoteFile[name=temp-SXNEb-multichunk-620d8153735fb2cfb98e88ddc80a453759dc4fd9], final location: RemoteFile[name=multichunk-620d8153735fb2cfb98e88ddc80a453759dc4fd9]
29-3-20 17:52:32.146 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=B/(A4,B1)/T=1585504352145, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-3-20 17:52:32.146 | UpOperation     | Test worker    | INFO : Saving local delta database, version B/(A4,B1)/T=1585504352145 to file /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/database-B-0000000001 ... 
29-3-20 17:52:32.146 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/database-B-0000000001 ...
29-3-20 17:52:32.147 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-3-20 17:52:32.147 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/database-B-0000000001 to RemoteFile[name=database-B-0000000001] ...
29-3-20 17:52:32.147 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/database-B-0000000001 -> Temp. remote file: RemoteFile[name=temp-OLkuO-database-B-0000000001], final location: RemoteFile[name=database-B-0000000001]
29-3-20 17:52:32.147 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-3-20 17:52:32.147 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-3-20 17:52:32.150 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/temp-transaction-17527238343671220965.tmp
29-3-20 17:52:32.150 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@f45502e) ...
29-3-20 17:52:32.150 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-18f1cfe3] ...
29-3-20 17:52:32.150 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-3-20 17:52:32.151 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@3f4a4fd9) ...
29-3-20 17:52:32.151 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/multichunk-620d8153735fb2cfb98e88ddc80a453759dc4fd9 to temp. file RemoteFile[name=temp-SXNEb-multichunk-620d8153735fb2cfb98e88ddc80a453759dc4fd9] ...
29-3-20 17:52:32.152 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@39b19b49) ...
29-3-20 17:52:32.153 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@6d0726a4) ...
29-3-20 17:52:32.154 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/database-B-0000000001 to temp. file RemoteFile[name=temp-OLkuO-database-B-0000000001] ...
29-3-20 17:52:32.157 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-SXNEb-multichunk-620d8153735fb2cfb98e88ddc80a453759dc4fd9] to final location RemoteFile[name=multichunk-620d8153735fb2cfb98e88ddc80a453759dc4fd9] ...
29-3-20 17:52:32.157 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-OLkuO-database-B-0000000001] to final location RemoteFile[name=database-B-0000000001] ...
29-3-20 17:52:32.158 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-18f1cfe3] ...
29-3-20 17:52:32.158 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-3-20 17:52:32.158 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-3-20 17:52:32.158 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version B/(A4,B1)/T=1585504352145) ...
29-3-20 17:52:32.160 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-3-20 17:52:32.165 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-3-20 17:52:32.169 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=B/(A4,B1)/T=1585504352145, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-3-20 17:52:32.169 | UpOperation     | Test worker    | INFO : Committing local database.
29-3-20 17:52:32.169 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-3-20 17:52:32.170 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504352161, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-3-20 17:52:32.170 | UpOperation     | Test worker    | INFO : Sync up done.
29-3-20 17:52:32.171 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-B-1585504352090] ...
29-3-20 17:52:32.172 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-B-1585504352090]
29-3-20 17:52:32.172 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:52:32.172 | Cache           | Test worker    | INFO : Cache size okay (156 KB), no need to clean (keep size is 500 MB)
29-3-20 17:52:32.172 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@346540ca) ...
29-3-20 17:52:32.173 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.173 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-C' ...
29-3-20 17:52:32.173 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.173 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.173 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.173 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.173 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.173 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.173 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.173 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.173 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.173 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-C' ...
29-3-20 17:52:32.173 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.173 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.174 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:52:32.174 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:52:32.174 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.174 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.174 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.174 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.174 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.174 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.174 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:52:32.174 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:52:32.189 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
29-3-20 17:52:32.189 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
29-3-20 17:52:32.194 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
29-3-20 17:52:32.197 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
29-3-20 17:52:32.200 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
29-3-20 17:52:32.204 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
29-3-20 17:52:32.204 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
29-3-20 17:52:32.204 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
29-3-20 17:52:32.204 | 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:52:32.207 | 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:52:32.208 | 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:52:32.210 | 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:52:32.212 | 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:52:32.214 | 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:52:32.215 | 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:52:32.217 | 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:52:32.219 | 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:52:32.221 | 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:52:32.223 | 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:52:32.225 | 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:52:32.226 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
29-3-20 17:52:32.226 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
29-3-20 17:52:32.227 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
29-3-20 17:52:32.229 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
29-3-20 17:52:32.230 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
29-3-20 17:52:32.232 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
29-3-20 17:52:32.233 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
29-3-20 17:52:32.235 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
29-3-20 17:52:32.238 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
29-3-20 17:52:32.238 | 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:52:32.241 | 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:52:32.242 | 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:52:32.244 | 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:52:32.246 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
29-3-20 17:52:32.246 | 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:52:32.248 | 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:52:32.250 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
29-3-20 17:52:32.250 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
29-3-20 17:52:32.250 | 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:52:32.252 | UpOperation     | Test worker    | INFO : 
29-3-20 17:52:32.252 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client C ...
29-3-20 17:52:32.252 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.252 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@13cc4ee2) ...
29-3-20 17:52:32.252 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.252 | StatusOperation | Test worker    | INFO : 
29-3-20 17:52:32.252 | StatusOperation | Test worker    | INFO : Running 'Status' at client C ...
29-3-20 17:52:32.252 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.252 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:52:32.252 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@2a2058e5) ...
29-3-20 17:52:32.253 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-21853-client-C ...
29-3-20 17:52:32.253 | StatusOperation | Test worker    | FINE : - New file: C1
29-3-20 17:52:32.253 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:52:32.253 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@37e17ed7) ...
29-3-20 17:52:32.253 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:52:32.254 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.254 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:52:32.254 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
29-3-20 17:52:32.254 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.254 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@2e01b930) ...
29-3-20 17:52:32.254 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:52:32.254 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is new.
29-3-20 17:52:32.255 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
29-3-20 17:52:32.255 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is new.
29-3-20 17:52:32.255 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
29-3-20 17:52:32.255 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is new.
29-3-20 17:52:32.255 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@72f3f1de) ...
29-3-20 17:52:32.255 | UpOperation     | Test worker    | INFO : There are remote changes. Call 'down' first or use --force-upload you must, Luke!
29-3-20 17:52:32.255 | UpOperation     | Test worker    | FINE : Unknown remote databases are: [RemoteFile[name=database-A-0000000004], RemoteFile[name=database-A-0000000002], RemoteFile[name=database-A-0000000003], RemoteFile[name=database-A-0000000001], RemoteFile[name=database-B-0000000001]]
29-3-20 17:52:32.255 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@1c76ef96) ...
29-3-20 17:52:32.256 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.256 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-C' ...
29-3-20 17:52:32.256 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.256 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.256 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.256 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.256 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.256 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.256 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.256 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.256 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.256 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-C' ...
29-3-20 17:52:32.256 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.256 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.256 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:52:32.256 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:52:32.256 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.256 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.256 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.256 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.256 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.256 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.256 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:52:32.256 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:52:32.257 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.257 | UpOperation     | Test worker    | INFO : 
29-3-20 17:52:32.257 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client C ...
29-3-20 17:52:32.257 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.257 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@3082936f) ...
29-3-20 17:52:32.258 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.258 | StatusOperation | Test worker    | INFO : 
29-3-20 17:52:32.258 | StatusOperation | Test worker    | INFO : Running 'Status' at client C ...
29-3-20 17:52:32.258 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.258 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:52:32.258 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@76b3b7db) ...
29-3-20 17:52:32.258 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-21853-client-C ...
29-3-20 17:52:32.259 | StatusOperation | Test worker    | FINE : - New file: C1
29-3-20 17:52:32.259 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:52:32.259 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@75eee487) ...
29-3-20 17:52:32.259 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:52:32.259 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.259 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:52:32.259 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
29-3-20 17:52:32.259 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.259 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@49232663) ...
29-3-20 17:52:32.260 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:52:32.260 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is new.
29-3-20 17:52:32.260 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
29-3-20 17:52:32.260 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is new.
29-3-20 17:52:32.260 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
29-3-20 17:52:32.260 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is new.
29-3-20 17:52:32.260 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@7d876814) ...
29-3-20 17:52:32.260 | UpOperation     | Test worker    | INFO : There are remote changes. Call 'down' first or use --force-upload you must, Luke!
29-3-20 17:52:32.260 | UpOperation     | Test worker    | FINE : Unknown remote databases are: [RemoteFile[name=database-A-0000000004], RemoteFile[name=database-A-0000000002], RemoteFile[name=database-A-0000000003], RemoteFile[name=database-A-0000000001], RemoteFile[name=database-B-0000000001]]
29-3-20 17:52:32.260 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@5ac4a50e) ...
29-3-20 17:52:32.260 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.260 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-C' ...
29-3-20 17:52:32.260 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.260 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.260 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.260 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.260 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.260 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.260 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.260 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.260 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.261 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-C' ...
29-3-20 17:52:32.261 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.261 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.261 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:52:32.261 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:52:32.261 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.261 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.261 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.261 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.261 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.261 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.261 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:52:32.261 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:52:32.262 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.262 | UpOperation     | Test worker    | INFO : 
29-3-20 17:52:32.262 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client C ...
29-3-20 17:52:32.262 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.262 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@ec282bc) ...
29-3-20 17:52:32.262 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.262 | StatusOperation | Test worker    | INFO : 
29-3-20 17:52:32.262 | StatusOperation | Test worker    | INFO : Running 'Status' at client C ...
29-3-20 17:52:32.262 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.262 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:52:32.262 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@37d0ac7b) ...
29-3-20 17:52:32.263 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-21853-client-C ...
29-3-20 17:52:32.263 | StatusOperation | Test worker    | FINE : - New file: C1
29-3-20 17:52:32.263 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:52:32.263 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@38ad61cc) ...
29-3-20 17:52:32.263 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:52:32.264 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.264 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:52:32.264 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
29-3-20 17:52:32.264 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.264 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@a2ad6bf) ...
29-3-20 17:52:32.264 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:52:32.264 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is new.
29-3-20 17:52:32.264 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
29-3-20 17:52:32.264 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is new.
29-3-20 17:52:32.264 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
29-3-20 17:52:32.264 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is new.
29-3-20 17:52:32.264 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@40236a78) ...
29-3-20 17:52:32.264 | UpOperation     | Test worker    | INFO : There are remote changes. Call 'down' first or use --force-upload you must, Luke!
29-3-20 17:52:32.264 | UpOperation     | Test worker    | FINE : Unknown remote databases are: [RemoteFile[name=database-A-0000000004], RemoteFile[name=database-A-0000000002], RemoteFile[name=database-A-0000000003], RemoteFile[name=database-A-0000000001], RemoteFile[name=database-B-0000000001]]
29-3-20 17:52:32.264 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@236f5636) ...
29-3-20 17:52:32.264 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.264 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-A' ...
29-3-20 17:52:32.264 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.264 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.264 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.264 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.265 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.265 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.265 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.265 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.265 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.265 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-A' ...
29-3-20 17:52:32.265 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.265 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.265 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:52:32.265 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:52:32.265 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.265 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.265 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.265 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.265 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.265 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.265 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:52:32.265 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:52:32.266 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.266 | DownOperation   | Test worker    | INFO : 
29-3-20 17:52:32.266 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client A ...
29-3-20 17:52:32.266 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.266 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@7224dbd2) ...
29-3-20 17:52:32.266 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:52:32.266 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.266 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:52:32.266 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:52:32.266 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.266 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@708822a5) ...
29-3-20 17:52:32.267 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:52:32.267 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
29-3-20 17:52:32.267 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-3-20 17:52:32.267 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
29-3-20 17:52:32.267 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:52:32.267 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is new.
29-3-20 17:52:32.267 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@3c8c1140) ...
29-3-20 17:52:32.267 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@6da8dcba) ...
29-3-20 17:52:32.267 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-A-1585504352265] ...
29-3-20 17:52:32.267 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-A-1585504352265]
29-3-20 17:52:32.267 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-A-1585504352265] ...
29-3-20 17:52:32.268 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
29-3-20 17:52:32.268 | DownOperation   | Test worker    | INFO : - Downloading database-B-0000000001 to local cache at /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-B-0000000001
29-3-20 17:52:32.268 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@7defd7df) ...
29-3-20 17:52:32.268 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
29-3-20 17:52:32.268 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-B-0000000001 ...
29-3-20 17:52:32.269 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A4,B1)/T=1585504352145
29-3-20 17:52:32.270 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.270 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.270 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.270 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.270 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.270 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
29-3-20 17:52:32.270 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1585504351878, A/(A2)/T=1585504351925, A/(A3)/T=1585504351950, A/(A4)/T=1585504351975], B=[B/(A4,B1)/T=1585504352145]}
29-3-20 17:52:32.270 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
29-3-20 17:52:32.270 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1585504351878
29-3-20 17:52:32.270 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1585504351925
29-3-20 17:52:32.270 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3)/T=1585504351950
29-3-20 17:52:32.270 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A4)/T=1585504351975
29-3-20 17:52:32.270 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A4,B1)/T=1585504352145
29-3-20 17:52:32.270 | DatabaseReconci | Test worker    | INFO : - Winner is B with branch: 
29-3-20 17:52:32.270 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1585504351878
29-3-20 17:52:32.270 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1585504351925
29-3-20 17:52:32.270 | DatabaseReconci | Test worker    | INFO :   + A/(A3)/T=1585504351950
29-3-20 17:52:32.270 | DatabaseReconci | Test worker    | INFO :   + A/(A4)/T=1585504351975
29-3-20 17:52:32.270 | DatabaseReconci | Test worker    | INFO :   + B/(A4,B1)/T=1585504352145
29-3-20 17:52:32.270 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
29-3-20 17:52:32.270 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
29-3-20 17:52:32.270 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
29-3-20 17:52:32.270 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1585504351878, A/(A2)/T=1585504351925, A/(A3)/T=1585504351950, A/(A4)/T=1585504351975]
29-3-20 17:52:32.271 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1585504351878, A/(A2)/T=1585504351925, A/(A3)/T=1585504351950, A/(A4)/T=1585504351975, B/(A4,B1)/T=1585504352145]
29-3-20 17:52:32.271 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
29-3-20 17:52:32.271 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [B/(A4,B1)/T=1585504352145]
29-3-20 17:52:32.271 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
29-3-20 17:52:32.271 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-B-0000000001 ...
29-3-20 17:52:32.272 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A4,B1)/T=1585504352145
29-3-20 17:52:32.272 | DownOperation   | Test worker    | INFO : Determine file system actions ...
29-3-20 17:52:32.273 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.273 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
29-3-20 17:52:32.273 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
29-3-20 17:52:32.273 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
29-3-20 17:52:32.273 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:32 UTC 2020, linkTarget=null, checksum=e555670dcd160e0370544dfcabb1ad489eac7cd2, updated=Sun Mar 29 17:52:32 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:52:32.274 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file A4,B1
29-3-20 17:52:32.274 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:32 UTC 2020, linkTarget=null, checksum=e555670dcd160e0370544dfcabb1ad489eac7cd2, updated=Sun Mar 29 17:52:32 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-200329175039872-21853-client-A/A4,B1
29-3-20 17:52:32.274 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:32 UTC 2020, linkTarget=null, checksum=e555670dcd160e0370544dfcabb1ad489eac7cd2, updated=Sun Mar 29 17:52:32 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:52:32.274 | DownOperation   | Test worker    | INFO :   + Adding multichunk 620d8153735fb2cfb98e88ddc80a453759dc4fd9 to download list ...
29-3-20 17:52:32.274 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
29-3-20 17:52:32.274 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@1dbbc2d2) ...
29-3-20 17:52:32.274 | Downloader      | Test worker    | INFO :   + Downloading multichunk 620d8153735fb2cfb98e88ddc80a453759dc4fd9 ...
29-3-20 17:52:32.275 | Downloader      | Test worker    | INFO :   + Decrypting multichunk 620d8153735fb2cfb98e88ddc80a453759dc4fd9 ...
29-3-20 17:52:32.275 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk 620d8153735fb2cfb98e88ddc80a453759dc4fd9 ...
29-3-20 17:52:32.276 | FileSystemActio | Test worker    | INFO :    Sorted actions:
29-3-20 17:52:32.276 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:32 UTC 2020, linkTarget=null, checksum=e555670dcd160e0370544dfcabb1ad489eac7cd2, updated=Sun Mar 29 17:52:32 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:52:32.276 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
29-3-20 17:52:32.276 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:32 UTC 2020, linkTarget=null, checksum=e555670dcd160e0370544dfcabb1ad489eac7cd2, updated=Sun Mar 29 17:52:32 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:52:32.276 | Assembler       | Test worker    | INFO :      - Creating file A4,B1 to /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/temp-reconstructedFileVersion-10742660253491184017.tmp ...
29-3-20 17:52:32.277 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
29-3-20 17:52:32.277 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
29-3-20 17:52:32.277 | DownOperation   | Test worker    | INFO :   + Applying database version (A4,B1)
29-3-20 17:52:32.277 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=B/(A4,B1)/T=1585504352145, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-3-20 17:52:32.283 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-A-1585504352265] ...
29-3-20 17:52:32.283 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-A-1585504352265]
29-3-20 17:52:32.283 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:52:32.283 | Cache           | Test worker    | INFO : Cache size okay (206 KB), no need to clean (keep size is 500 MB)
29-3-20 17:52:32.283 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@143b6757) ...
29-3-20 17:52:32.283 | DownOperation   | Test worker    | INFO : Sync down done.
29-3-20 17:52:32.287 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-200329175039872-21853-client-A/A2, but actual PATH = tmp/syncanytest/syncany-200329175039872-21853-client-B/A2, for file tmp/syncanytest/syncany-200329175039872-21853-client-B/A2
29-3-20 17:52:32.289 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-200329175039872-21853-client-A/A4,B1, but actual PATH = tmp/syncanytest/syncany-200329175039872-21853-client-B/A4,B1, for file tmp/syncanytest/syncany-200329175039872-21853-client-B/A4,B1
29-3-20 17:52:32.290 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.290 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-B' ...
29-3-20 17:52:32.290 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.290 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.290 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.290 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.290 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.290 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.290 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.290 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.290 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.290 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-B' ...
29-3-20 17:52:32.290 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.290 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.290 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:52:32.290 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:52:32.290 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.290 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.291 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.291 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.291 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.291 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.291 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:52:32.291 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:52:32.291 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.291 | DownOperation   | Test worker    | INFO : 
29-3-20 17:52:32.291 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
29-3-20 17:52:32.291 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.291 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@42b7fd5) ...
29-3-20 17:52:32.291 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:52:32.292 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.292 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:52:32.292 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
29-3-20 17:52:32.292 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.292 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@6ce966bb) ...
29-3-20 17:52:32.292 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:52:32.292 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
29-3-20 17:52:32.293 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-3-20 17:52:32.293 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
29-3-20 17:52:32.293 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:52:32.293 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
29-3-20 17:52:32.293 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@15f356f1) ...
29-3-20 17:52:32.293 | DownOperation   | Test worker    | INFO : * Nothing new. Skipping down operation.
29-3-20 17:52:32.293 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@71b39acd) ...
29-3-20 17:52:32.297 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.297 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-C' ...
29-3-20 17:52:32.297 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.297 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.297 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.297 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.297 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.297 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.298 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.298 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.298 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.298 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-C' ...
29-3-20 17:52:32.298 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.298 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.298 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:52:32.298 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:52:32.298 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.298 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.298 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.298 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.298 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.298 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.298 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:52:32.298 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:52:32.299 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.299 | DownOperation   | Test worker    | INFO : 
29-3-20 17:52:32.299 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client C ...
29-3-20 17:52:32.299 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.299 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@251320d0) ...
29-3-20 17:52:32.299 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:52:32.299 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.299 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:52:32.299 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
29-3-20 17:52:32.299 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.299 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@27a9b9a3) ...
29-3-20 17:52:32.300 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:52:32.300 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is new.
29-3-20 17:52:32.300 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
29-3-20 17:52:32.300 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is new.
29-3-20 17:52:32.300 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
29-3-20 17:52:32.300 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is new.
29-3-20 17:52:32.300 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@1b920862) ...
29-3-20 17:52:32.300 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@79b2c806) ...
29-3-20 17:52:32.300 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-C-1585504352298] ...
29-3-20 17:52:32.300 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-C-1585504352298]
29-3-20 17:52:32.300 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-C-1585504352298] ...
29-3-20 17:52:32.300 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
29-3-20 17:52:32.300 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000004 to local cache at /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/database-A-0000000004
29-3-20 17:52:32.300 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@62e8b17d) ...
29-3-20 17:52:32.301 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000002 to local cache at /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/database-A-0000000002
29-3-20 17:52:32.301 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@df5b7de) ...
29-3-20 17:52:32.301 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000003 to local cache at /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/database-A-0000000003
29-3-20 17:52:32.301 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@7eab99c0) ...
29-3-20 17:52:32.301 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000001 to local cache at /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/database-A-0000000001
29-3-20 17:52:32.301 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@4ca7049) ...
29-3-20 17:52:32.302 | DownOperation   | Test worker    | INFO : - Downloading database-B-0000000001 to local cache at /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/database-B-0000000001
29-3-20 17:52:32.302 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@238e5af4) ...
29-3-20 17:52:32.302 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
29-3-20 17:52:32.302 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/database-A-0000000001 ...
29-3-20 17:52:32.303 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1585504351878
29-3-20 17:52:32.303 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/database-A-0000000002 ...
29-3-20 17:52:32.305 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1585504351925
29-3-20 17:52:32.306 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/database-A-0000000003 ...
29-3-20 17:52:32.306 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A3)/T=1585504351950
29-3-20 17:52:32.307 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/database-A-0000000004 ...
29-3-20 17:52:32.307 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A4)/T=1585504351975
29-3-20 17:52:32.307 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/database-B-0000000001 ...
29-3-20 17:52:32.308 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A4,B1)/T=1585504352145
29-3-20 17:52:32.309 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.309 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.309 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.309 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.309 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.309 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
29-3-20 17:52:32.309 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1585504351878, A/(A2)/T=1585504351925, A/(A3)/T=1585504351950, A/(A4)/T=1585504351975], B=[B/(A4,B1)/T=1585504352145], C=[]}
29-3-20 17:52:32.309 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
29-3-20 17:52:32.309 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1585504351878
29-3-20 17:52:32.309 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1585504351925
29-3-20 17:52:32.309 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3)/T=1585504351950
29-3-20 17:52:32.309 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A4)/T=1585504351975
29-3-20 17:52:32.309 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A4,B1)/T=1585504352145
29-3-20 17:52:32.309 | DatabaseReconci | Test worker    | INFO : - Winner is B with branch: 
29-3-20 17:52:32.309 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1585504351878
29-3-20 17:52:32.309 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1585504351925
29-3-20 17:52:32.309 | DatabaseReconci | Test worker    | INFO :   + A/(A3)/T=1585504351950
29-3-20 17:52:32.309 | DatabaseReconci | Test worker    | INFO :   + A/(A4)/T=1585504351975
29-3-20 17:52:32.309 | DatabaseReconci | Test worker    | INFO :   + B/(A4,B1)/T=1585504352145
29-3-20 17:52:32.309 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
29-3-20 17:52:32.309 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
29-3-20 17:52:32.309 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
29-3-20 17:52:32.309 | DatabaseReconci | Test worker    | INFO : Losers Branch: []
29-3-20 17:52:32.310 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1585504351878, A/(A2)/T=1585504351925, A/(A3)/T=1585504351950, A/(A4)/T=1585504351975, B/(A4,B1)/T=1585504352145]
29-3-20 17:52:32.310 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
29-3-20 17:52:32.310 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A1)/T=1585504351878, A/(A2)/T=1585504351925, A/(A3)/T=1585504351950, A/(A4)/T=1585504351975, B/(A4,B1)/T=1585504352145]
29-3-20 17:52:32.310 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
29-3-20 17:52:32.310 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/database-A-0000000001 ...
29-3-20 17:52:32.311 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1585504351878
29-3-20 17:52:32.311 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/database-A-0000000002 ...
29-3-20 17:52:32.311 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1585504351925
29-3-20 17:52:32.312 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/database-A-0000000003 ...
29-3-20 17:52:32.312 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A3)/T=1585504351950
29-3-20 17:52:32.313 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/database-A-0000000004 ...
29-3-20 17:52:32.313 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A4)/T=1585504351975
29-3-20 17:52:32.313 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/database-B-0000000001 ...
29-3-20 17:52:32.314 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A4,B1)/T=1585504352145
29-3-20 17:52:32.314 | DownOperation   | Test worker    | INFO : Determine file system actions ...
29-3-20 17:52:32.315 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.316 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
29-3-20 17:52:32.316 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
29-3-20 17:52:32.316 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
29-3-20 17:52:32.316 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:32 UTC 2020, linkTarget=null, checksum=e555670dcd160e0370544dfcabb1ad489eac7cd2, updated=Sun Mar 29 17:52:32 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:52:32.316 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file A4,B1
29-3-20 17:52:32.316 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:32 UTC 2020, linkTarget=null, checksum=e555670dcd160e0370544dfcabb1ad489eac7cd2, updated=Sun Mar 29 17:52:32 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-200329175039872-21853-client-C/A4,B1
29-3-20 17:52:32.316 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:32 UTC 2020, linkTarget=null, checksum=e555670dcd160e0370544dfcabb1ad489eac7cd2, updated=Sun Mar 29 17:52:32 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:52:32.316 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
29-3-20 17:52:32.316 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=2, path=A3, type=FILE, status=DELETED, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=474def2a9811b6928ec7d88632e2a7be551a2ed5, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:52:32.316 | FileVersionComp | Test worker    | INFO :      - []: Local file does not exist, and expected file was deleted, for file A3
29-3-20 17:52:32.316 | FileSystemActio | Test worker    | INFO :      -> (1) Equals: Nothing to do, winning version equals winning file: FileVersion [version=2, path=A3, type=FILE, status=DELETED, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=474def2a9811b6928ec7d88632e2a7be551a2ed5, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-200329175039872-21853-client-C/A3
29-3-20 17:52:32.316 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
29-3-20 17:52:32.316 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=8e1961d4a5e0b420cdcf5ecd2293f364212eb454, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:52:32.316 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file A2
29-3-20 17:52:32.316 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=8e1961d4a5e0b420cdcf5ecd2293f364212eb454, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-200329175039872-21853-client-C/A2
29-3-20 17:52:32.316 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=8e1961d4a5e0b420cdcf5ecd2293f364212eb454, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:52:32.317 | DownOperation   | Test worker    | INFO :   + Adding multichunk 620d8153735fb2cfb98e88ddc80a453759dc4fd9 to download list ...
29-3-20 17:52:32.317 | DownOperation   | Test worker    | INFO :   + Adding multichunk 90b412e08871e882fe6fa8ce9352a727345a9545 to download list ...
29-3-20 17:52:32.317 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
29-3-20 17:52:32.317 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@7ead123b) ...
29-3-20 17:52:32.317 | Downloader      | Test worker    | INFO :   + Downloading multichunk 90b412e08871e882fe6fa8ce9352a727345a9545 ...
29-3-20 17:52:32.318 | Downloader      | Test worker    | INFO :   + Decrypting multichunk 90b412e08871e882fe6fa8ce9352a727345a9545 ...
29-3-20 17:52:32.318 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk 90b412e08871e882fe6fa8ce9352a727345a9545 ...
29-3-20 17:52:32.319 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@61a8d45d) ...
29-3-20 17:52:32.319 | Downloader      | Test worker    | INFO :   + Downloading multichunk 620d8153735fb2cfb98e88ddc80a453759dc4fd9 ...
29-3-20 17:52:32.319 | Downloader      | Test worker    | INFO :   + Decrypting multichunk 620d8153735fb2cfb98e88ddc80a453759dc4fd9 ...
29-3-20 17:52:32.319 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk 620d8153735fb2cfb98e88ddc80a453759dc4fd9 ...
29-3-20 17:52:32.319 | FileSystemActio | Test worker    | INFO :    Sorted actions:
29-3-20 17:52:32.320 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=8e1961d4a5e0b420cdcf5ecd2293f364212eb454, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:52:32.320 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:32 UTC 2020, linkTarget=null, checksum=e555670dcd160e0370544dfcabb1ad489eac7cd2, updated=Sun Mar 29 17:52:32 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:52:32.320 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
29-3-20 17:52:32.320 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Mar 29 17:52:31 UTC 2020, linkTarget=null, checksum=8e1961d4a5e0b420cdcf5ecd2293f364212eb454, updated=Sun Mar 29 17:52:31 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:52:32.320 | Assembler       | Test worker    | INFO :      - Creating file A2 to /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/temp-reconstructedFileVersion-16848742399326660388.tmp ...
29-3-20 17:52:32.321 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
29-3-20 17:52:32.321 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:32 UTC 2020, linkTarget=null, checksum=e555670dcd160e0370544dfcabb1ad489eac7cd2, updated=Sun Mar 29 17:52:32 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:52:32.321 | Assembler       | Test worker    | INFO :      - Creating file A4,B1 to /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/temp-reconstructedFileVersion-16948318388012854255.tmp ...
29-3-20 17:52:32.322 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
29-3-20 17:52:32.322 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
29-3-20 17:52:32.322 | DownOperation   | Test worker    | INFO :   + Applying database version (A1)
29-3-20 17:52:32.322 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A1)/T=1585504351878, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-3-20 17:52:32.324 | DownOperation   | Test worker    | INFO :   + Applying database version (A2)
29-3-20 17:52:32.324 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A2)/T=1585504351925, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:52:32.325 | DownOperation   | Test worker    | INFO :   + Applying database version (A3)
29-3-20 17:52:32.325 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A3)/T=1585504351950, chunks=2, multiChunks=1, fileContents=2, fileHistories=2]
29-3-20 17:52:32.327 | DownOperation   | Test worker    | INFO :   + Applying database version (A4)
29-3-20 17:52:32.327 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A4)/T=1585504351975, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:52:32.327 | DownOperation   | Test worker    | INFO :   + Applying database version (A4,B1)
29-3-20 17:52:32.327 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=B/(A4,B1)/T=1585504352145, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-3-20 17:52:32.334 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-C-1585504352298] ...
29-3-20 17:52:32.336 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-C-1585504352298]
29-3-20 17:52:32.336 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:52:32.336 | Cache           | Test worker    | INFO : Cache size okay (156 KB), no need to clean (keep size is 500 MB)
29-3-20 17:52:32.336 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@5ed76f6c) ...
29-3-20 17:52:32.336 | DownOperation   | Test worker    | INFO : Sync down done.
29-3-20 17:52:32.338 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.339 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-A' ...
29-3-20 17:52:32.339 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.339 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.339 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.339 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.339 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.339 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.339 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.339 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.339 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.339 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-A' ...
29-3-20 17:52:32.339 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.339 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.339 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:52:32.339 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:52:32.339 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.339 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.339 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.339 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.339 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.339 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.339 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:52:32.339 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:52:32.340 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.340 | UpOperation     | Test worker    | INFO : 
29-3-20 17:52:32.340 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
29-3-20 17:52:32.340 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.340 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@42ac24e5) ...
29-3-20 17:52:32.341 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.341 | StatusOperation | Test worker    | INFO : 
29-3-20 17:52:32.341 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-3-20 17:52:32.341 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.341 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:52:32.341 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@5cfe6f4a) ...
29-3-20 17:52:32.342 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-21853-client-A ...
29-3-20 17:52:32.343 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:52:32.343 | StatusOperation | Test worker    | INFO : - No changes to local database
29-3-20 17:52:32.343 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@52abb006) ...
29-3-20 17:52:32.343 | UpOperation     | Test worker    | INFO : Local database is up-to-date (change set). NOTHING TO DO!
29-3-20 17:52:32.343 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@1971a39a) ...
29-3-20 17:52:32.344 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.344 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-B' ...
29-3-20 17:52:32.344 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.344 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.344 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.344 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.344 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.344 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.344 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.344 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.344 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.344 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-B' ...
29-3-20 17:52:32.344 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.344 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.344 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:52:32.344 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:52:32.344 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.344 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.344 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.344 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.344 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.344 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.344 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:52:32.344 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:52:32.348 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.349 | UpOperation     | Test worker    | INFO : 
29-3-20 17:52:32.349 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client B ...
29-3-20 17:52:32.349 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.349 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@6b55753f) ...
29-3-20 17:52:32.349 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.349 | StatusOperation | Test worker    | INFO : 
29-3-20 17:52:32.349 | StatusOperation | Test worker    | INFO : Running 'Status' at client B ...
29-3-20 17:52:32.349 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.349 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:52:32.349 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@7008c1b4) ...
29-3-20 17:52:32.350 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-21853-client-B ...
29-3-20 17:52:32.350 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:52:32.350 | StatusOperation | Test worker    | INFO : - No changes to local database
29-3-20 17:52:32.350 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@5239a8ca) ...
29-3-20 17:52:32.350 | UpOperation     | Test worker    | INFO : Local database is up-to-date (change set). NOTHING TO DO!
29-3-20 17:52:32.350 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@3b32958b) ...
29-3-20 17:52:32.350 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.351 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-C' ...
29-3-20 17:52:32.351 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.351 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.351 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.351 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.351 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.351 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.351 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.351 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.351 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.351 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-C' ...
29-3-20 17:52:32.351 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.351 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.351 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:52:32.351 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:52:32.351 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.351 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.351 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.351 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.351 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.351 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.351 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:52:32.351 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:52:32.352 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.352 | UpOperation     | Test worker    | INFO : 
29-3-20 17:52:32.352 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client C ...
29-3-20 17:52:32.352 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.352 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@2e9b6a9b) ...
29-3-20 17:52:32.352 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.352 | StatusOperation | Test worker    | INFO : 
29-3-20 17:52:32.352 | StatusOperation | Test worker    | INFO : Running 'Status' at client C ...
29-3-20 17:52:32.353 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.353 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:52:32.353 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@1e4abd03) ...
29-3-20 17:52:32.353 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-21853-client-C ...
29-3-20 17:52:32.353 | StatusOperation | Test worker    | FINE : - New file: C1
29-3-20 17:52:32.354 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:52:32.354 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@79364b25) ...
29-3-20 17:52:32.354 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:52:32.354 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.354 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:52:32.354 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
29-3-20 17:52:32.354 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.354 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@5c83edfd) ...
29-3-20 17:52:32.355 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:52:32.355 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
29-3-20 17:52:32.355 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-3-20 17:52:32.355 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
29-3-20 17:52:32.355 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:52:32.355 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
29-3-20 17:52:32.355 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@4da3e792) ...
29-3-20 17:52:32.355 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-3-20 17:52:32.355 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-C-1585504352351] ...
29-3-20 17:52:32.355 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-C-1585504352351]
29-3-20 17:52:32.355 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-C-1585504352351] ...
29-3-20 17:52:32.356 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.356 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-3-20 17:52:32.356 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-3-20 17:52:32.356 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@46a77411) ...
29-3-20 17:52:32.356 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-3-20 17:52:32.357 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-200329175039872-21853-client-C/C1
29-3-20 17:52:32.357 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-200329175039872-21853-client-C/C1
29-3-20 17:52:32.359 | Indexer         | AsyncI/syncany | FINE : - Chunk new: 792d3575fa4023635a410e2853bd49bc4bd289c5
29-3-20 17:52:32.359 | Indexer         | AsyncI/syncany | FINE : - +MultiChunk abca263daca3a75ffb9c3c2ba91755489e31efa3
29-3-20 17:52:32.360 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: 792d3575fa4023635a410e2853bd49bc4bd289c5 > abca263daca3a75ffb9c3c2ba91755489e31efa3
29-3-20 17:52:32.360 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 792d3575fa4023635a410e2853bd49bc4bd289c5 > /tmp/syncanytest/syncany-200329175039872-21853-client-C/C1
29-3-20 17:52:32.360 | Indexer         | AsyncI/syncany | FINE : - /File: C1 (checksum 792d3575fa4023635a410e2853bd49bc4bd289c5)
29-3-20 17:52:32.361 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: C1, checksum: 792d3575fa4023635a410e2853bd49bc4bd289c5)
29-3-20 17:52:32.361 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file C1
29-3-20 17:52:32.361 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:32 UTC 2020, linkTarget=null, checksum=792d3575fa4023635a410e2853bd49bc4bd289c5, updated=Sun Mar 29 17:52:32 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:52:32.361 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
29-3-20 17:52:32.361 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@265f6cd4) ...
29-3-20 17:52:32.361 | Indexer         | AsyncI/syncany | FINE : - /MultiChunk abca263daca3a75ffb9c3c2ba91755489e31efa3
29-3-20 17:52:32.361 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@4d9de2bf) ...
29-3-20 17:52:32.361 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504352356, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-3-20 17:52:32.361 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-3-20 17:52:32.362 | UpOperation     | Test worker    | INFO : Last vector clock was: (A4,B1)
29-3-20 17:52:32.362 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-3-20 17:52:32.362 | UpOperation     | Test worker    | INFO : - Uploading multichunk abca263daca3a75ffb9c3c2ba91755489e31efa3 from /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/multichunk-abca263daca3a75ffb9c3c2ba91755489e31efa3 to RemoteFile[name=multichunk-abca263daca3a75ffb9c3c2ba91755489e31efa3] ...
29-3-20 17:52:32.362 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/multichunk-abca263daca3a75ffb9c3c2ba91755489e31efa3 -> Temp. remote file: RemoteFile[name=temp-FygQz-multichunk-abca263daca3a75ffb9c3c2ba91755489e31efa3], final location: RemoteFile[name=multichunk-abca263daca3a75ffb9c3c2ba91755489e31efa3]
29-3-20 17:52:32.362 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=C/(A4,B1,C1)/T=1585504352362, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-3-20 17:52:32.363 | UpOperation     | Test worker    | INFO : Saving local delta database, version C/(A4,B1,C1)/T=1585504352362 to file /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/database-C-0000000001 ... 
29-3-20 17:52:32.363 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/database-C-0000000001 ...
29-3-20 17:52:32.363 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-3-20 17:52:32.363 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/database-C-0000000001 to RemoteFile[name=database-C-0000000001] ...
29-3-20 17:52:32.363 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/database-C-0000000001 -> Temp. remote file: RemoteFile[name=temp-ugcQZ-database-C-0000000001], final location: RemoteFile[name=database-C-0000000001]
29-3-20 17:52:32.363 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-3-20 17:52:32.363 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-3-20 17:52:32.367 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/temp-transaction-2473706936796745585.tmp
29-3-20 17:52:32.367 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@501e2090) ...
29-3-20 17:52:32.367 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-2d1f9b87] ...
29-3-20 17:52:32.367 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-3-20 17:52:32.367 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@58ec634c) ...
29-3-20 17:52:32.368 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/multichunk-abca263daca3a75ffb9c3c2ba91755489e31efa3 to temp. file RemoteFile[name=temp-FygQz-multichunk-abca263daca3a75ffb9c3c2ba91755489e31efa3] ...
29-3-20 17:52:32.368 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@14d86f5a) ...
29-3-20 17:52:32.368 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-21853-client-C/.syncany/cache/database-C-0000000001 to temp. file RemoteFile[name=temp-ugcQZ-database-C-0000000001] ...
29-3-20 17:52:32.368 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-FygQz-multichunk-abca263daca3a75ffb9c3c2ba91755489e31efa3] to final location RemoteFile[name=multichunk-abca263daca3a75ffb9c3c2ba91755489e31efa3] ...
29-3-20 17:52:32.368 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-ugcQZ-database-C-0000000001] to final location RemoteFile[name=database-C-0000000001] ...
29-3-20 17:52:32.368 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-2d1f9b87] ...
29-3-20 17:52:32.368 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-3-20 17:52:32.369 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-3-20 17:52:32.369 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version C/(A4,B1,C1)/T=1585504352362) ...
29-3-20 17:52:32.370 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-3-20 17:52:32.371 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@283e1a48) ...
29-3-20 17:52:32.374 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-3-20 17:52:32.381 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=C/(A4,B1,C1)/T=1585504352362, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-3-20 17:52:32.381 | UpOperation     | Test worker    | INFO : Committing local database.
29-3-20 17:52:32.381 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-3-20 17:52:32.381 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504352375, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-3-20 17:52:32.381 | UpOperation     | Test worker    | INFO : Sync up done.
29-3-20 17:52:32.383 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-C-1585504352351] ...
29-3-20 17:52:32.384 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-C-1585504352351]
29-3-20 17:52:32.384 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:52:32.384 | Cache           | Test worker    | INFO : Cache size okay (207 KB), no need to clean (keep size is 500 MB)
29-3-20 17:52:32.384 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@4b36fc03) ...
29-3-20 17:52:32.384 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.384 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-A' ...
29-3-20 17:52:32.384 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.384 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.384 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.384 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.384 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.384 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.384 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.384 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.385 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.385 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-A' ...
29-3-20 17:52:32.385 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.385 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.385 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:52:32.385 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:52:32.385 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.385 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.385 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.385 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.385 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.385 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.385 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:52:32.385 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:52:32.388 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.388 | DownOperation   | Test worker    | INFO : 
29-3-20 17:52:32.388 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client A ...
29-3-20 17:52:32.388 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.388 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@3d25e0b) ...
29-3-20 17:52:32.389 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:52:32.389 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.389 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:52:32.389 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:52:32.389 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.389 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@b17308) ...
29-3-20 17:52:32.389 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:52:32.390 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
29-3-20 17:52:32.390 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-3-20 17:52:32.390 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
29-3-20 17:52:32.390 | LsRemoteOperati | Test worker    | INFO : - Remote database database-C-0000000001 is new.
29-3-20 17:52:32.390 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:52:32.390 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
29-3-20 17:52:32.390 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@2f0bd03f) ...
29-3-20 17:52:32.390 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@945131c) ...
29-3-20 17:52:32.390 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-A-1585504352385] ...
29-3-20 17:52:32.390 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-A-1585504352385]
29-3-20 17:52:32.390 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-A-1585504352385] ...
29-3-20 17:52:32.390 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
29-3-20 17:52:32.390 | DownOperation   | Test worker    | INFO : - Downloading database-C-0000000001 to local cache at /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-C-0000000001
29-3-20 17:52:32.390 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@ac2d98d) ...
29-3-20 17:52:32.391 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
29-3-20 17:52:32.391 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-C-0000000001 ...
29-3-20 17:52:32.392 | DatabaseXmlPars | Test worker    | INFO :    + Added database version C/(A4,B1,C1)/T=1585504352362
29-3-20 17:52:32.392 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.392 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.392 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.392 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.392 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.392 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-C-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.393 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
29-3-20 17:52:32.393 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1585504351878, A/(A2)/T=1585504351925, A/(A3)/T=1585504351950, A/(A4)/T=1585504351975, B/(A4,B1)/T=1585504352145], C=[C/(A4,B1,C1)/T=1585504352362]}
29-3-20 17:52:32.393 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
29-3-20 17:52:32.393 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1585504351878
29-3-20 17:52:32.393 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1585504351925
29-3-20 17:52:32.393 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3)/T=1585504351950
29-3-20 17:52:32.393 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A4)/T=1585504351975
29-3-20 17:52:32.393 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A4,B1)/T=1585504352145
29-3-20 17:52:32.393 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: C/(A4,B1,C1)/T=1585504352362
29-3-20 17:52:32.393 | DatabaseReconci | Test worker    | INFO : - Winner is C with branch: 
29-3-20 17:52:32.393 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1585504351878
29-3-20 17:52:32.393 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1585504351925
29-3-20 17:52:32.393 | DatabaseReconci | Test worker    | INFO :   + A/(A3)/T=1585504351950
29-3-20 17:52:32.393 | DatabaseReconci | Test worker    | INFO :   + A/(A4)/T=1585504351975
29-3-20 17:52:32.393 | DatabaseReconci | Test worker    | INFO :   + B/(A4,B1)/T=1585504352145
29-3-20 17:52:32.393 | DatabaseReconci | Test worker    | INFO :   + C/(A4,B1,C1)/T=1585504352362
29-3-20 17:52:32.393 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
29-3-20 17:52:32.393 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
29-3-20 17:52:32.393 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
29-3-20 17:52:32.393 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1585504351878, A/(A2)/T=1585504351925, A/(A3)/T=1585504351950, A/(A4)/T=1585504351975, B/(A4,B1)/T=1585504352145]
29-3-20 17:52:32.393 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1585504351878, A/(A2)/T=1585504351925, A/(A3)/T=1585504351950, A/(A4)/T=1585504351975, B/(A4,B1)/T=1585504352145, C/(A4,B1,C1)/T=1585504352362]
29-3-20 17:52:32.393 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
29-3-20 17:52:32.393 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [C/(A4,B1,C1)/T=1585504352362]
29-3-20 17:52:32.393 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
29-3-20 17:52:32.393 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/database-C-0000000001 ...
29-3-20 17:52:32.394 | DatabaseXmlPars | Test worker    | INFO :    + Added database version C/(A4,B1,C1)/T=1585504352362
29-3-20 17:52:32.394 | DownOperation   | Test worker    | INFO : Determine file system actions ...
29-3-20 17:52:32.395 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.395 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
29-3-20 17:52:32.395 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
29-3-20 17:52:32.395 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
29-3-20 17:52:32.396 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:32 UTC 2020, linkTarget=null, checksum=792d3575fa4023635a410e2853bd49bc4bd289c5, updated=Sun Mar 29 17:52:32 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:52:32.396 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file C1
29-3-20 17:52:32.396 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:32 UTC 2020, linkTarget=null, checksum=792d3575fa4023635a410e2853bd49bc4bd289c5, updated=Sun Mar 29 17:52:32 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-200329175039872-21853-client-A/C1
29-3-20 17:52:32.396 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:32 UTC 2020, linkTarget=null, checksum=792d3575fa4023635a410e2853bd49bc4bd289c5, updated=Sun Mar 29 17:52:32 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:52:32.396 | DownOperation   | Test worker    | INFO :   + Adding multichunk abca263daca3a75ffb9c3c2ba91755489e31efa3 to download list ...
29-3-20 17:52:32.396 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
29-3-20 17:52:32.396 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@1cc073c3) ...
29-3-20 17:52:32.397 | Downloader      | Test worker    | INFO :   + Downloading multichunk abca263daca3a75ffb9c3c2ba91755489e31efa3 ...
29-3-20 17:52:32.397 | Downloader      | Test worker    | INFO :   + Decrypting multichunk abca263daca3a75ffb9c3c2ba91755489e31efa3 ...
29-3-20 17:52:32.397 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk abca263daca3a75ffb9c3c2ba91755489e31efa3 ...
29-3-20 17:52:32.397 | FileSystemActio | Test worker    | INFO :    Sorted actions:
29-3-20 17:52:32.398 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:32 UTC 2020, linkTarget=null, checksum=792d3575fa4023635a410e2853bd49bc4bd289c5, updated=Sun Mar 29 17:52:32 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:52:32.398 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
29-3-20 17:52:32.398 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:32 UTC 2020, linkTarget=null, checksum=792d3575fa4023635a410e2853bd49bc4bd289c5, updated=Sun Mar 29 17:52:32 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:52:32.398 | Assembler       | Test worker    | INFO :      - Creating file C1 to /tmp/syncanytest/syncany-200329175039872-21853-client-A/.syncany/cache/temp-reconstructedFileVersion-2203034843238946416.tmp ...
29-3-20 17:52:32.400 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
29-3-20 17:52:32.400 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
29-3-20 17:52:32.400 | DownOperation   | Test worker    | INFO :   + Applying database version (A4,B1,C1)
29-3-20 17:52:32.400 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=C/(A4,B1,C1)/T=1585504352362, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-3-20 17:52:32.406 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-A-1585504352385] ...
29-3-20 17:52:32.408 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-A-1585504352385]
29-3-20 17:52:32.408 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:52:32.408 | Cache           | Test worker    | INFO : Cache size okay (257 KB), no need to clean (keep size is 500 MB)
29-3-20 17:52:32.408 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@7c5a2aed) ...
29-3-20 17:52:32.408 | DownOperation   | Test worker    | INFO : Sync down done.
29-3-20 17:52:32.408 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.408 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-B' ...
29-3-20 17:52:32.408 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.408 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.408 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.408 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.408 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.408 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.408 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.408 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.409 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.409 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-B' ...
29-3-20 17:52:32.409 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.409 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.409 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:52:32.409 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:52:32.409 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.409 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.409 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.409 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.409 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.409 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.409 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:52:32.409 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:52:32.411 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.412 | DownOperation   | Test worker    | INFO : 
29-3-20 17:52:32.412 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
29-3-20 17:52:32.412 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.412 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@2309d80c) ...
29-3-20 17:52:32.412 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:52:32.412 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.412 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:52:32.412 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
29-3-20 17:52:32.412 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.412 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@73cea639) ...
29-3-20 17:52:32.412 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:52:32.413 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
29-3-20 17:52:32.413 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-3-20 17:52:32.413 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
29-3-20 17:52:32.413 | LsRemoteOperati | Test worker    | INFO : - Remote database database-C-0000000001 is new.
29-3-20 17:52:32.413 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:52:32.413 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
29-3-20 17:52:32.413 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@2f34ec5) ...
29-3-20 17:52:32.413 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@2ba608fa) ...
29-3-20 17:52:32.413 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1585504352409] ...
29-3-20 17:52:32.413 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1585504352409]
29-3-20 17:52:32.413 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1585504352409] ...
29-3-20 17:52:32.413 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
29-3-20 17:52:32.413 | DownOperation   | Test worker    | INFO : - Downloading database-C-0000000001 to local cache at /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/database-C-0000000001
29-3-20 17:52:32.413 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@6357cc59) ...
29-3-20 17:52:32.414 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
29-3-20 17:52:32.414 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/database-C-0000000001 ...
29-3-20 17:52:32.415 | DatabaseXmlPars | Test worker    | INFO :    + Added database version C/(A4,B1,C1)/T=1585504352362
29-3-20 17:52:32.415 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.415 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.415 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.415 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.415 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.415 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-21853-repo/databases/database-C-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:52:32.415 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
29-3-20 17:52:32.415 | DownOperation   | Test worker    | INFO : Populated unknown branches: {B=[A/(A1)/T=1585504351878, A/(A2)/T=1585504351925, A/(A3)/T=1585504351950, A/(A4)/T=1585504351975, B/(A4,B1)/T=1585504352145], C=[C/(A4,B1,C1)/T=1585504352362]}
29-3-20 17:52:32.415 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
29-3-20 17:52:32.416 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1585504351878
29-3-20 17:52:32.416 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1585504351925
29-3-20 17:52:32.416 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3)/T=1585504351950
29-3-20 17:52:32.416 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A4)/T=1585504351975
29-3-20 17:52:32.416 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A4,B1)/T=1585504352145
29-3-20 17:52:32.416 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: C/(A4,B1,C1)/T=1585504352362
29-3-20 17:52:32.416 | DatabaseReconci | Test worker    | INFO : - Winner is C with branch: 
29-3-20 17:52:32.416 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1585504351878
29-3-20 17:52:32.416 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1585504351925
29-3-20 17:52:32.416 | DatabaseReconci | Test worker    | INFO :   + A/(A3)/T=1585504351950
29-3-20 17:52:32.416 | DatabaseReconci | Test worker    | INFO :   + A/(A4)/T=1585504351975
29-3-20 17:52:32.416 | DatabaseReconci | Test worker    | INFO :   + B/(A4,B1)/T=1585504352145
29-3-20 17:52:32.416 | DatabaseReconci | Test worker    | INFO :   + C/(A4,B1,C1)/T=1585504352362
29-3-20 17:52:32.416 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
29-3-20 17:52:32.416 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
29-3-20 17:52:32.416 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
29-3-20 17:52:32.416 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1585504351878, A/(A2)/T=1585504351925, A/(A3)/T=1585504351950, A/(A4)/T=1585504351975, B/(A4,B1)/T=1585504352145]
29-3-20 17:52:32.416 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1585504351878, A/(A2)/T=1585504351925, A/(A3)/T=1585504351950, A/(A4)/T=1585504351975, B/(A4,B1)/T=1585504352145, C/(A4,B1,C1)/T=1585504352362]
29-3-20 17:52:32.416 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
29-3-20 17:52:32.416 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [C/(A4,B1,C1)/T=1585504352362]
29-3-20 17:52:32.416 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
29-3-20 17:52:32.417 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/database-C-0000000001 ...
29-3-20 17:52:32.418 | DatabaseXmlPars | Test worker    | INFO :    + Added database version C/(A4,B1,C1)/T=1585504352362
29-3-20 17:52:32.418 | DownOperation   | Test worker    | INFO : Determine file system actions ...
29-3-20 17:52:32.419 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.419 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
29-3-20 17:52:32.419 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
29-3-20 17:52:32.419 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
29-3-20 17:52:32.419 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:32 UTC 2020, linkTarget=null, checksum=792d3575fa4023635a410e2853bd49bc4bd289c5, updated=Sun Mar 29 17:52:32 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:52:32.419 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file C1
29-3-20 17:52:32.420 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:32 UTC 2020, linkTarget=null, checksum=792d3575fa4023635a410e2853bd49bc4bd289c5, updated=Sun Mar 29 17:52:32 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-200329175039872-21853-client-B/C1
29-3-20 17:52:32.420 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:32 UTC 2020, linkTarget=null, checksum=792d3575fa4023635a410e2853bd49bc4bd289c5, updated=Sun Mar 29 17:52:32 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:52:32.420 | DownOperation   | Test worker    | INFO :   + Adding multichunk abca263daca3a75ffb9c3c2ba91755489e31efa3 to download list ...
29-3-20 17:52:32.420 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
29-3-20 17:52:32.420 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@643ed2f1) ...
29-3-20 17:52:32.420 | Downloader      | Test worker    | INFO :   + Downloading multichunk abca263daca3a75ffb9c3c2ba91755489e31efa3 ...
29-3-20 17:52:32.421 | Downloader      | Test worker    | INFO :   + Decrypting multichunk abca263daca3a75ffb9c3c2ba91755489e31efa3 ...
29-3-20 17:52:32.421 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk abca263daca3a75ffb9c3c2ba91755489e31efa3 ...
29-3-20 17:52:32.421 | FileSystemActio | Test worker    | INFO :    Sorted actions:
29-3-20 17:52:32.421 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:32 UTC 2020, linkTarget=null, checksum=792d3575fa4023635a410e2853bd49bc4bd289c5, updated=Sun Mar 29 17:52:32 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:52:32.421 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
29-3-20 17:52:32.421 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:52:32 UTC 2020, linkTarget=null, checksum=792d3575fa4023635a410e2853bd49bc4bd289c5, updated=Sun Mar 29 17:52:32 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:52:32.421 | Assembler       | Test worker    | INFO :      - Creating file C1 to /tmp/syncanytest/syncany-200329175039872-21853-client-B/.syncany/cache/temp-reconstructedFileVersion-10114882414879660962.tmp ...
29-3-20 17:52:32.422 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
29-3-20 17:52:32.423 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
29-3-20 17:52:32.423 | DownOperation   | Test worker    | INFO :   + Applying database version (A4,B1,C1)
29-3-20 17:52:32.423 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=C/(A4,B1,C1)/T=1585504352362, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
29-3-20 17:52:32.428 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1585504352409] ...
29-3-20 17:52:32.432 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1585504352409]
29-3-20 17:52:32.432 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:52:32.432 | Cache           | Test worker    | INFO : Cache size okay (207 KB), no need to clean (keep size is 500 MB)
29-3-20 17:52:32.432 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@29240030) ...
29-3-20 17:52:32.432 | DownOperation   | Test worker    | INFO : Sync down done.
29-3-20 17:52:32.432 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.432 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-C' ...
29-3-20 17:52:32.432 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.432 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.432 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.432 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.432 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.432 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.432 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.432 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.433 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:52:32.433 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-21853-client-C' ...
29-3-20 17:52:32.433 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:52:32.433 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:52:32.433 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:52:32.433 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:52:32.433 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:52:32.433 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:52:32.433 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:52:32.433 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:52:32.433 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:52:32.433 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:52:32.433 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:52:32.433 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:52:32.434 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.434 | DownOperation   | Test worker    | INFO : 
29-3-20 17:52:32.434 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client C ...
29-3-20 17:52:32.434 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.434 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@2d9d4284) ...
29-3-20 17:52:32.434 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:52:32.434 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:52:32.434 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:52:32.434 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
29-3-20 17:52:32.434 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:52:32.434 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@24240830) ...
29-3-20 17:52:32.435 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:52:32.435 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
29-3-20 17:52:32.435 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
29-3-20 17:52:32.435 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
29-3-20 17:52:32.435 | LsRemoteOperati | Test worker    | INFO : - Remote database database-C-0000000001 is already known (in local database). Ignoring.
29-3-20 17:52:32.435 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:52:32.435 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
29-3-20 17:52:32.435 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@3ba5c3b1) ...
29-3-20 17:52:32.435 | DownOperation   | Test worker    | INFO : * Nothing new. Skipping down operation.
29-3-20 17:52:32.435 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@53842d44) ...
29-3-20 17:52:32.439 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-200329175039872-21853-client-A/A2, but actual PATH = tmp/syncanytest/syncany-200329175039872-21853-client-B/A2, for file tmp/syncanytest/syncany-200329175039872-21853-client-B/A2
29-3-20 17:52:32.441 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-200329175039872-21853-client-A/A4,B1, but actual PATH = tmp/syncanytest/syncany-200329175039872-21853-client-B/A4,B1, for file tmp/syncanytest/syncany-200329175039872-21853-client-B/A4,B1
29-3-20 17:52:32.443 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-200329175039872-21853-client-A/C1, but actual PATH = tmp/syncanytest/syncany-200329175039872-21853-client-B/C1, for file tmp/syncanytest/syncany-200329175039872-21853-client-B/C1
29-3-20 17:52:32.447 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-200329175039872-21853-client-B/A2, but actual PATH = tmp/syncanytest/syncany-200329175039872-21853-client-C/A2, for file tmp/syncanytest/syncany-200329175039872-21853-client-C/A2
29-3-20 17:52:32.449 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-200329175039872-21853-client-B/A4,B1, but actual PATH = tmp/syncanytest/syncany-200329175039872-21853-client-C/A4,B1, for file tmp/syncanytest/syncany-200329175039872-21853-client-C/A4,B1
29-3-20 17:52:32.450 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-200329175039872-21853-client-B/C1, but actual PATH = tmp/syncanytest/syncany-200329175039872-21853-client-C/C1, for file tmp/syncanytest/syncany-200329175039872-21853-client-C/C1