Class org.syncany.tests.integration.scenarios.SymlinkSyncScenarioTest

3

tests

0

failures

0

ignored

0.956s

duration

100%

successful

Tests

Test Duration Result
testSymlinkMultipleUpsAndDowns 0.274s passed
testSymlinkOneUpOneDown 0.264s passed
testSymlinkSyncToNonExistingFolder 0.418s passed

Standard error

29-3-20 17:53:22.285 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:22.285 | LocalTransferMa | Test worker    | INFO : testTargetExists: Target exists.
29-3-20 17:53:22.289 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:22.290 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-45561-client-A' ...
29-3-20 17:53:22.290 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:22.290 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:22.290 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:22.290 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:22.290 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:22.290 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:22.290 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:22.290 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:22.290 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:22.290 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-45561-client-A' ...
29-3-20 17:53:22.290 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:22.290 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:22.295 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:22.295 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:22.295 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:22.295 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:22.295 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:22.295 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:22.295 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:22.295 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:22.295 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:22.295 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:22.309 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
29-3-20 17:53:22.310 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
29-3-20 17:53:22.319 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
29-3-20 17:53:22.321 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
29-3-20 17:53:22.321 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
29-3-20 17:53:22.324 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
29-3-20 17:53:22.324 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
29-3-20 17:53:22.325 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
29-3-20 17:53:22.325 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS databaseversion ( id int NOT NULL IDENTITY, status varchar(45) NOT NULL, localtime datetime NOT NULL, client varchar(45) NOT NULL, vectorclock_serialized varchar(1024) NOT NULL, UNIQUE (vectorclock_serialized) ); 
29-3-20 17:53:22.326 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  chunk ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.328 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  databaseversion_vectorclock ( databaseversion_id int NOT NULL, client varchar(45) NOT NULL, logicaltime int NOT NULL, PRIMARY KEY (databaseversion_id, client), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.329 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.330 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent_chunk ( filecontent_checksum varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, num int NOT NULL, PRIMARY KEY (filecontent_checksum, chunk_checksum, num), FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.332 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filehistory ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, PRIMARY KEY (id, databaseversion_id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.339 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  fileversion ( filehistory_id varchar(40) NOT NULL, version int NOT NULL, databaseversion_id int NOT NULL, path varchar(1024) NOT NULL, type varchar(45) NOT NULL, status varchar(45) NOT NULL, size bigint NOT NULL, lastmodified datetime NOT NULL, linktarget varchar(1024), filecontent_checksum varchar(40) DEFAULT NULL, updated datetime NOT NULL, posixperms varchar(45) DEFAULT NULL, dosattrs varchar(45) DEFAULT NULL, PRIMARY KEY (filehistory_id, version, databaseversion_id), FOREIGN KEY (filehistory_id, databaseversion_id) REFERENCES filehistory (id, databaseversion_id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.341 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.342 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_chunk ( multichunk_id varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, PRIMARY KEY (multichunk_id, chunk_checksum), FOREIGN KEY (multichunk_id) REFERENCES multichunk (id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.343 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_muddy ( id varchar(40) NOT NULL, machine_name varchar(255) NOT NULL, machine_version int NOT NULL, PRIMARY KEY (id) ); 
29-3-20 17:53:22.345 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  known_databases ( id int NOT NULL IDENTITY, client varchar(45) NOT NULL, filenumber int NOT NULL, UNIQUE (client, filenumber) ); 
29-3-20 17:53:22.346 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  general_settings ( key varchar(255) NOT NULL, value varchar(255) NOT NULL, PRIMARY KEY (key) ); 
29-3-20 17:53:22.347 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
29-3-20 17:53:22.347 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
29-3-20 17:53:22.348 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
29-3-20 17:53:22.350 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
29-3-20 17:53:22.351 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
29-3-20 17:53:22.352 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
29-3-20 17:53:22.353 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
29-3-20 17:53:22.354 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
29-3-20 17:53:22.356 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
29-3-20 17:53:22.356 | SqlRunner       | Test worker    | INFO : SQL:    CREATE VIEW databaseversion_master AS SELECT dbv.*, vc.logicaltime as client_version FROM databaseversion dbv JOIN databaseversion_vectorclock vc on dbv.id=vc.databaseversion_id and dbv.client=vc.client WHERE dbv.status='MASTER'; 
29-3-20 17:53:22.357 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master AS SELECT fv0.* FROM fileversion fv0 JOIN databaseversion dbv ON fv0.databaseversion_id=dbv.id AND dbv.status='MASTER'; 
29-3-20 17:53:22.358 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_maxversion AS SELECT DISTINCT filehistory_id, MAX(version) version FROM fileversion_master GROUP BY filehistory_id; 
29-3-20 17:53:22.360 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_last AS SELECT fv.* FROM fileversion_master_maxversion fvmax JOIN fileversion_master fv ON fvmax.filehistory_id=fv.filehistory_id AND fvmax.version=fv.version WHERE fv.status<>'DELETED'; 
29-3-20 17:53:22.362 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
29-3-20 17:53:22.362 | SqlRunner       | Test worker    | INFO : SQL:    create view filehistory_full as select dbv.status as databaseversion_status, dbv.localtime as databaseversion_localtime, dbv.client as databaseversion_client, dbv.vectorclock_serialized as databaseversion_vectorclock_serialized, fh.* from databaseversion dbv join filehistory fh on dbv.id=fh.databaseversion_id; 
29-3-20 17:53:22.363 | SqlRunner       | Test worker    | INFO : SQL:  create view fileversion_full as select fhf.databaseversion_status, fhf.databaseversion_localtime, fhf.databaseversion_client, fhf.databaseversion_vectorclock_serialized, fv.* from filehistory_full fhf join fileversion fv on fhf.id=fv.filehistory_id and fhf.databaseversion_id=fv.databaseversion_id; 
29-3-20 17:53:22.365 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
29-3-20 17:53:22.365 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
29-3-20 17:53:22.365 | SqlRunner       | Test worker    | INFO : SQL:     create function substr_count(haystack varchar(255), needle varchar(255)) returns integer begin atomic declare strCount integer; declare lastIndex integer;  set strCount = 0; set lastIndex = 1;  while lastIndex <> 0 do set lastIndex = locate(needle, haystack, lastIndex);  if lastIndex <> 0 then set strCount = strCount + 1; set lastIndex = lastIndex + length(needle); end if; end while;  return strCount; end; 
29-3-20 17:53:22.368 | UpOperation     | Test worker    | INFO : 
29-3-20 17:53:22.368 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
29-3-20 17:53:22.368 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:22.368 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@3bccdd0b) ...
29-3-20 17:53:22.368 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:22.368 | StatusOperation | Test worker    | INFO : 
29-3-20 17:53:22.368 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-3-20 17:53:22.368 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:22.368 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:53:22.368 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@33f0cdb0) ...
29-3-20 17:53:22.369 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-45561-client-A ...
29-3-20 17:53:22.369 | StatusOperation | Test worker    | FINE : - New file: symlink-name
29-3-20 17:53:22.369 | StatusOperation | Test worker    | FINE : - New file: symlink-target
29-3-20 17:53:22.369 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:53:22.369 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@23d7b3b9) ...
29-3-20 17:53:22.369 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:22.370 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:22.370 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:22.370 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:53:22.370 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:22.370 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@16eb3162) ...
29-3-20 17:53:22.370 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:22.370 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@3217410f) ...
29-3-20 17:53:22.370 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-3-20 17:53:22.370 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1585504402295] ...
29-3-20 17:53:22.370 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1585504402295]
29-3-20 17:53:22.370 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1585504402295] ...
29-3-20 17:53:22.371 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:22.376 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-3-20 17:53:22.376 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-3-20 17:53:22.376 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@1cf173cd) ...
29-3-20 17:53:22.376 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-3-20 17:53:22.376 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-200329175039872-45561-client-A/symlink-name
29-3-20 17:53:22.377 | Indexer         | AsyncI/syncany | FINE : - /File: symlink-name (directory/symlink/0-byte-file)
29-3-20 17:53:22.377 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: symlink-name, SYMLINK)
29-3-20 17:53:22.377 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file symlink-name
29-3-20 17:53:22.377 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=14, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=symlink-target, checksum=null, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rwxrwxrwx, dosAttributes=--a-]
29-3-20 17:53:22.377 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
29-3-20 17:53:22.377 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@27840da6) ...
29-3-20 17:53:22.377 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-200329175039872-45561-client-A/symlink-target
29-3-20 17:53:22.377 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-200329175039872-45561-client-A/symlink-target
29-3-20 17:53:22.381 | Indexer         | AsyncI/syncany | FINE : - Chunk new: 37b63ffdf24f9997c5a836a7e3ff1c601c5d228d
29-3-20 17:53:22.381 | Indexer         | AsyncI/syncany | FINE : - +MultiChunk bc0c1aeffb35501b637a89625ee5f435def26fe9
29-3-20 17:53:22.382 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: 37b63ffdf24f9997c5a836a7e3ff1c601c5d228d > bc0c1aeffb35501b637a89625ee5f435def26fe9
29-3-20 17:53:22.382 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 37b63ffdf24f9997c5a836a7e3ff1c601c5d228d > /tmp/syncanytest/syncany-200329175039872-45561-client-A/symlink-target
29-3-20 17:53:22.382 | Indexer         | AsyncI/syncany | FINE : - /File: symlink-target (checksum 37b63ffdf24f9997c5a836a7e3ff1c601c5d228d)
29-3-20 17:53:22.383 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: symlink-target, checksum: 37b63ffdf24f9997c5a836a7e3ff1c601c5d228d)
29-3-20 17:53:22.383 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file symlink-target
29-3-20 17:53:22.383 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=symlink-target, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=null, checksum=37b63ffdf24f9997c5a836a7e3ff1c601c5d228d, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:22.383 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
29-3-20 17:53:22.383 | Indexer         | AsyncI/syncany | FINE : - /MultiChunk bc0c1aeffb35501b637a89625ee5f435def26fe9
29-3-20 17:53:22.383 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@28d5840c) ...
29-3-20 17:53:22.383 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504402376, chunks=1, multiChunks=1, fileContents=1, fileHistories=2]
29-3-20 17:53:22.383 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-3-20 17:53:22.383 | UpOperation     | Test worker    | INFO : Last vector clock was: ()
29-3-20 17:53:22.384 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-3-20 17:53:22.384 | UpOperation     | Test worker    | INFO : - Uploading multichunk bc0c1aeffb35501b637a89625ee5f435def26fe9 from /tmp/syncanytest/syncany-200329175039872-45561-client-A/.syncany/cache/multichunk-bc0c1aeffb35501b637a89625ee5f435def26fe9 to RemoteFile[name=multichunk-bc0c1aeffb35501b637a89625ee5f435def26fe9] ...
29-3-20 17:53:22.384 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-45561-client-A/.syncany/cache/multichunk-bc0c1aeffb35501b637a89625ee5f435def26fe9 -> Temp. remote file: RemoteFile[name=temp-raJDV-multichunk-bc0c1aeffb35501b637a89625ee5f435def26fe9], final location: RemoteFile[name=multichunk-bc0c1aeffb35501b637a89625ee5f435def26fe9]
29-3-20 17:53:22.384 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A1)/T=1585504402384, chunks=1, multiChunks=1, fileContents=1, fileHistories=2]
29-3-20 17:53:22.384 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A1)/T=1585504402384 to file /tmp/syncanytest/syncany-200329175039872-45561-client-A/.syncany/cache/database-A-0000000001 ... 
29-3-20 17:53:22.384 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-200329175039872-45561-client-A/.syncany/cache/database-A-0000000001 ...
29-3-20 17:53:22.385 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-3-20 17:53:22.385 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-45561-client-A/.syncany/cache/database-A-0000000001 to RemoteFile[name=database-A-0000000001] ...
29-3-20 17:53:22.385 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-45561-client-A/.syncany/cache/database-A-0000000001 -> Temp. remote file: RemoteFile[name=temp-iHCap-database-A-0000000001], final location: RemoteFile[name=database-A-0000000001]
29-3-20 17:53:22.385 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-3-20 17:53:22.385 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-3-20 17:53:22.386 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-200329175039872-45561-client-A/.syncany/cache/temp-transaction-472300576119793907.tmp
29-3-20 17:53:22.386 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@44f58eaf) ...
29-3-20 17:53:22.386 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-29708c3e] ...
29-3-20 17:53:22.386 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-3-20 17:53:22.386 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@72e2564c) ...
29-3-20 17:53:22.386 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-45561-client-A/.syncany/cache/multichunk-bc0c1aeffb35501b637a89625ee5f435def26fe9 to temp. file RemoteFile[name=temp-raJDV-multichunk-bc0c1aeffb35501b637a89625ee5f435def26fe9] ...
29-3-20 17:53:22.386 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@1e26b3f4) ...
29-3-20 17:53:22.386 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-45561-client-A/.syncany/cache/database-A-0000000001 to temp. file RemoteFile[name=temp-iHCap-database-A-0000000001] ...
29-3-20 17:53:22.387 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-raJDV-multichunk-bc0c1aeffb35501b637a89625ee5f435def26fe9] to final location RemoteFile[name=multichunk-bc0c1aeffb35501b637a89625ee5f435def26fe9] ...
29-3-20 17:53:22.387 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-iHCap-database-A-0000000001] to final location RemoteFile[name=database-A-0000000001] ...
29-3-20 17:53:22.387 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-29708c3e] ...
29-3-20 17:53:22.387 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-3-20 17:53:22.387 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-3-20 17:53:22.387 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A1)/T=1585504402384) ...
29-3-20 17:53:22.388 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-3-20 17:53:22.400 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@baa8026) ...
29-3-20 17:53:22.400 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A1)/T=1585504402384, chunks=1, multiChunks=1, fileContents=1, fileHistories=2]
29-3-20 17:53:22.400 | UpOperation     | Test worker    | INFO : Committing local database.
29-3-20 17:53:22.400 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-3-20 17:53:22.401 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-3-20 17:53:22.402 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504402401, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-3-20 17:53:22.402 | UpOperation     | Test worker    | INFO : Sync up done.
29-3-20 17:53:22.403 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1585504402295] ...
29-3-20 17:53:22.406 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1585504402295]
29-3-20 17:53:22.406 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:22.406 | Cache           | Test worker    | INFO : Cache size okay (51 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:22.406 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@6ca04377) ...
29-3-20 17:53:22.406 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:22.406 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-45561-client-B' ...
29-3-20 17:53:22.406 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:22.406 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:22.406 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:22.406 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:22.406 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:22.406 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:22.406 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:22.406 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:22.406 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:22.406 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-45561-client-B' ...
29-3-20 17:53:22.406 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:22.406 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:22.406 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:22.406 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:22.406 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:22.406 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:22.406 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:22.406 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:22.406 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:22.407 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:22.407 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:22.407 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:22.421 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
29-3-20 17:53:22.422 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
29-3-20 17:53:22.428 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
29-3-20 17:53:22.431 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
29-3-20 17:53:22.431 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
29-3-20 17:53:22.435 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
29-3-20 17:53:22.435 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
29-3-20 17:53:22.435 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
29-3-20 17:53:22.435 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS databaseversion ( id int NOT NULL IDENTITY, status varchar(45) NOT NULL, localtime datetime NOT NULL, client varchar(45) NOT NULL, vectorclock_serialized varchar(1024) NOT NULL, UNIQUE (vectorclock_serialized) ); 
29-3-20 17:53:22.436 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  chunk ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.438 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  databaseversion_vectorclock ( databaseversion_id int NOT NULL, client varchar(45) NOT NULL, logicaltime int NOT NULL, PRIMARY KEY (databaseversion_id, client), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.439 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.441 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent_chunk ( filecontent_checksum varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, num int NOT NULL, PRIMARY KEY (filecontent_checksum, chunk_checksum, num), FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.442 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filehistory ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, PRIMARY KEY (id, databaseversion_id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.444 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  fileversion ( filehistory_id varchar(40) NOT NULL, version int NOT NULL, databaseversion_id int NOT NULL, path varchar(1024) NOT NULL, type varchar(45) NOT NULL, status varchar(45) NOT NULL, size bigint NOT NULL, lastmodified datetime NOT NULL, linktarget varchar(1024), filecontent_checksum varchar(40) DEFAULT NULL, updated datetime NOT NULL, posixperms varchar(45) DEFAULT NULL, dosattrs varchar(45) DEFAULT NULL, PRIMARY KEY (filehistory_id, version, databaseversion_id), FOREIGN KEY (filehistory_id, databaseversion_id) REFERENCES filehistory (id, databaseversion_id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.445 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.447 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_chunk ( multichunk_id varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, PRIMARY KEY (multichunk_id, chunk_checksum), FOREIGN KEY (multichunk_id) REFERENCES multichunk (id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.448 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_muddy ( id varchar(40) NOT NULL, machine_name varchar(255) NOT NULL, machine_version int NOT NULL, PRIMARY KEY (id) ); 
29-3-20 17:53:22.450 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  known_databases ( id int NOT NULL IDENTITY, client varchar(45) NOT NULL, filenumber int NOT NULL, UNIQUE (client, filenumber) ); 
29-3-20 17:53:22.451 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  general_settings ( key varchar(255) NOT NULL, value varchar(255) NOT NULL, PRIMARY KEY (key) ); 
29-3-20 17:53:22.452 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
29-3-20 17:53:22.452 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
29-3-20 17:53:22.453 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
29-3-20 17:53:22.455 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
29-3-20 17:53:22.456 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
29-3-20 17:53:22.457 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
29-3-20 17:53:22.458 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
29-3-20 17:53:22.459 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
29-3-20 17:53:22.461 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
29-3-20 17:53:22.461 | SqlRunner       | Test worker    | INFO : SQL:    CREATE VIEW databaseversion_master AS SELECT dbv.*, vc.logicaltime as client_version FROM databaseversion dbv JOIN databaseversion_vectorclock vc on dbv.id=vc.databaseversion_id and dbv.client=vc.client WHERE dbv.status='MASTER'; 
29-3-20 17:53:22.462 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master AS SELECT fv0.* FROM fileversion fv0 JOIN databaseversion dbv ON fv0.databaseversion_id=dbv.id AND dbv.status='MASTER'; 
29-3-20 17:53:22.463 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_maxversion AS SELECT DISTINCT filehistory_id, MAX(version) version FROM fileversion_master GROUP BY filehistory_id; 
29-3-20 17:53:22.465 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_last AS SELECT fv.* FROM fileversion_master_maxversion fvmax JOIN fileversion_master fv ON fvmax.filehistory_id=fv.filehistory_id AND fvmax.version=fv.version WHERE fv.status<>'DELETED'; 
29-3-20 17:53:22.467 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
29-3-20 17:53:22.467 | SqlRunner       | Test worker    | INFO : SQL:    create view filehistory_full as select dbv.status as databaseversion_status, dbv.localtime as databaseversion_localtime, dbv.client as databaseversion_client, dbv.vectorclock_serialized as databaseversion_vectorclock_serialized, fh.* from databaseversion dbv join filehistory fh on dbv.id=fh.databaseversion_id; 
29-3-20 17:53:22.468 | SqlRunner       | Test worker    | INFO : SQL:  create view fileversion_full as select fhf.databaseversion_status, fhf.databaseversion_localtime, fhf.databaseversion_client, fhf.databaseversion_vectorclock_serialized, fv.* from filehistory_full fhf join fileversion fv on fhf.id=fv.filehistory_id and fhf.databaseversion_id=fv.databaseversion_id; 
29-3-20 17:53:22.470 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
29-3-20 17:53:22.470 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
29-3-20 17:53:22.470 | SqlRunner       | Test worker    | INFO : SQL:     create function substr_count(haystack varchar(255), needle varchar(255)) returns integer begin atomic declare strCount integer; declare lastIndex integer;  set strCount = 0; set lastIndex = 1;  while lastIndex <> 0 do set lastIndex = locate(needle, haystack, lastIndex);  if lastIndex <> 0 then set strCount = strCount + 1; set lastIndex = lastIndex + length(needle); end if; end while;  return strCount; end; 
29-3-20 17:53:22.471 | DownOperation   | Test worker    | INFO : 
29-3-20 17:53:22.471 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
29-3-20 17:53:22.471 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:22.471 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@72295b53) ...
29-3-20 17:53:22.471 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:22.472 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:22.472 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:22.472 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
29-3-20 17:53:22.472 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:22.472 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@39258182) ...
29-3-20 17:53:22.472 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:22.472 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
29-3-20 17:53:22.472 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@ae3643a) ...
29-3-20 17:53:22.472 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@110568d) ...
29-3-20 17:53:22.473 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1585504402407] ...
29-3-20 17:53:22.473 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1585504402407]
29-3-20 17:53:22.473 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1585504402407] ...
29-3-20 17:53:22.473 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
29-3-20 17:53:22.473 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000001 to local cache at /tmp/syncanytest/syncany-200329175039872-45561-client-B/.syncany/cache/database-A-0000000001
29-3-20 17:53:22.473 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@753093fe) ...
29-3-20 17:53:22.473 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
29-3-20 17:53:22.473 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-200329175039872-45561-client-B/.syncany/cache/database-A-0000000001 ...
29-3-20 17:53:22.475 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1585504402384
29-3-20 17:53:22.475 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-45561-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:22.475 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
29-3-20 17:53:22.475 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1585504402384], B=[]}
29-3-20 17:53:22.475 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
29-3-20 17:53:22.475 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1585504402384
29-3-20 17:53:22.475 | DatabaseReconci | Test worker    | INFO : - Winner is A with branch: 
29-3-20 17:53:22.475 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1585504402384
29-3-20 17:53:22.475 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
29-3-20 17:53:22.475 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
29-3-20 17:53:22.475 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
29-3-20 17:53:22.475 | DatabaseReconci | Test worker    | INFO : Losers Branch: []
29-3-20 17:53:22.475 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1585504402384]
29-3-20 17:53:22.475 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
29-3-20 17:53:22.475 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A1)/T=1585504402384]
29-3-20 17:53:22.475 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
29-3-20 17:53:22.475 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-200329175039872-45561-client-B/.syncany/cache/database-A-0000000001 ...
29-3-20 17:53:22.484 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1585504402384
29-3-20 17:53:22.484 | DownOperation   | Test worker    | INFO : Determine file system actions ...
29-3-20 17:53:22.485 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:22.485 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
29-3-20 17:53:22.485 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
29-3-20 17:53:22.485 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
29-3-20 17:53:22.486 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=14, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=symlink-target, checksum=null, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rwxrwxrwx, dosAttributes=--a-]
29-3-20 17:53:22.486 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file symlink-name
29-3-20 17:53:22.486 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=14, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=symlink-target, checksum=null, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rwxrwxrwx, dosAttributes=--a-] AND /tmp/syncanytest/syncany-200329175039872-45561-client-B/symlink-name
29-3-20 17:53:22.486 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=14, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=symlink-target, checksum=null, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rwxrwxrwx, dosAttributes=--a-]]
29-3-20 17:53:22.486 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
29-3-20 17:53:22.486 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=symlink-target, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=null, checksum=37b63ffdf24f9997c5a836a7e3ff1c601c5d228d, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]
29-3-20 17:53:22.487 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file symlink-target
29-3-20 17:53:22.487 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=1, path=symlink-target, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=null, checksum=37b63ffdf24f9997c5a836a7e3ff1c601c5d228d, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-200329175039872-45561-client-B/symlink-target
29-3-20 17:53:22.487 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=symlink-target, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=null, checksum=37b63ffdf24f9997c5a836a7e3ff1c601c5d228d, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:22.487 | DownOperation   | Test worker    | INFO :   + Adding multichunk bc0c1aeffb35501b637a89625ee5f435def26fe9 to download list ...
29-3-20 17:53:22.487 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
29-3-20 17:53:22.487 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@2f9e4a5d) ...
29-3-20 17:53:22.487 | Downloader      | Test worker    | INFO :   + Downloading multichunk bc0c1aeffb35501b637a89625ee5f435def26fe9 ...
29-3-20 17:53:22.497 | Downloader      | Test worker    | INFO :   + Decrypting multichunk bc0c1aeffb35501b637a89625ee5f435def26fe9 ...
29-3-20 17:53:22.497 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk bc0c1aeffb35501b637a89625ee5f435def26fe9 ...
29-3-20 17:53:22.497 | FileSystemActio | Test worker    | INFO :    Sorted actions:
29-3-20 17:53:22.497 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=symlink-target, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=null, checksum=37b63ffdf24f9997c5a836a7e3ff1c601c5d228d, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:22.498 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=14, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=symlink-target, checksum=null, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rwxrwxrwx, dosAttributes=--a-]]
29-3-20 17:53:22.498 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
29-3-20 17:53:22.498 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=symlink-target, type=FILE, status=NEW, size=51200, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=null, checksum=37b63ffdf24f9997c5a836a7e3ff1c601c5d228d, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
29-3-20 17:53:22.498 | Assembler       | Test worker    | INFO :      - Creating file symlink-target to /tmp/syncanytest/syncany-200329175039872-45561-client-B/.syncany/cache/temp-reconstructedFileVersion-11059512191360041541.tmp ...
29-3-20 17:53:22.499 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
29-3-20 17:53:22.499 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=14, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=symlink-target, checksum=null, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rwxrwxrwx, dosAttributes=--a-]]
29-3-20 17:53:22.499 | FileSystemActio | Test worker    | INFO :      - Creating symlink at /tmp/syncanytest/syncany-200329175039872-45561-client-B/symlink-name (target: symlink-target) ...
29-3-20 17:53:22.499 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
29-3-20 17:53:22.499 | DownOperation   | Test worker    | INFO :   + Applying database version (A1)
29-3-20 17:53:22.499 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A1)/T=1585504402384, chunks=1, multiChunks=1, fileContents=1, fileHistories=2]
29-3-20 17:53:22.548 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1585504402407] ...
29-3-20 17:53:22.556 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1585504402407]
29-3-20 17:53:22.556 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:22.556 | Cache           | Test worker    | INFO : Cache size okay (51 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:22.556 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@638c781d) ...
29-3-20 17:53:22.556 | DownOperation   | Test worker    | INFO : Sync down done.
29-3-20 17:53:22.559 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:22.560 | LocalTransferMa | Test worker    | INFO : testTargetExists: Target exists.
29-3-20 17:53:22.570 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:22.570 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-87808-client-A' ...
29-3-20 17:53:22.570 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:22.570 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:22.570 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:22.570 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:22.570 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:22.570 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:22.570 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:22.570 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:22.571 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:22.571 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-87808-client-A' ...
29-3-20 17:53:22.571 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:22.571 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:22.571 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:22.571 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:22.571 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:22.571 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:22.571 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:22.571 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:22.571 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:22.571 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:22.571 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:22.575 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:22.591 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
29-3-20 17:53:22.592 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
29-3-20 17:53:22.601 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
29-3-20 17:53:22.603 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
29-3-20 17:53:22.603 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
29-3-20 17:53:22.606 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
29-3-20 17:53:22.606 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
29-3-20 17:53:22.607 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
29-3-20 17:53:22.607 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS databaseversion ( id int NOT NULL IDENTITY, status varchar(45) NOT NULL, localtime datetime NOT NULL, client varchar(45) NOT NULL, vectorclock_serialized varchar(1024) NOT NULL, UNIQUE (vectorclock_serialized) ); 
29-3-20 17:53:22.609 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  chunk ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.610 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  databaseversion_vectorclock ( databaseversion_id int NOT NULL, client varchar(45) NOT NULL, logicaltime int NOT NULL, PRIMARY KEY (databaseversion_id, client), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.611 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.613 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent_chunk ( filecontent_checksum varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, num int NOT NULL, PRIMARY KEY (filecontent_checksum, chunk_checksum, num), FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.614 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filehistory ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, PRIMARY KEY (id, databaseversion_id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.615 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  fileversion ( filehistory_id varchar(40) NOT NULL, version int NOT NULL, databaseversion_id int NOT NULL, path varchar(1024) NOT NULL, type varchar(45) NOT NULL, status varchar(45) NOT NULL, size bigint NOT NULL, lastmodified datetime NOT NULL, linktarget varchar(1024), filecontent_checksum varchar(40) DEFAULT NULL, updated datetime NOT NULL, posixperms varchar(45) DEFAULT NULL, dosattrs varchar(45) DEFAULT NULL, PRIMARY KEY (filehistory_id, version, databaseversion_id), FOREIGN KEY (filehistory_id, databaseversion_id) REFERENCES filehistory (id, databaseversion_id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.617 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.618 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_chunk ( multichunk_id varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, PRIMARY KEY (multichunk_id, chunk_checksum), FOREIGN KEY (multichunk_id) REFERENCES multichunk (id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.620 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_muddy ( id varchar(40) NOT NULL, machine_name varchar(255) NOT NULL, machine_version int NOT NULL, PRIMARY KEY (id) ); 
29-3-20 17:53:22.621 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  known_databases ( id int NOT NULL IDENTITY, client varchar(45) NOT NULL, filenumber int NOT NULL, UNIQUE (client, filenumber) ); 
29-3-20 17:53:22.623 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  general_settings ( key varchar(255) NOT NULL, value varchar(255) NOT NULL, PRIMARY KEY (key) ); 
29-3-20 17:53:22.624 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
29-3-20 17:53:22.624 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
29-3-20 17:53:22.656 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
29-3-20 17:53:22.661 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
29-3-20 17:53:22.662 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
29-3-20 17:53:22.663 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
29-3-20 17:53:22.665 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
29-3-20 17:53:22.666 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
29-3-20 17:53:22.667 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
29-3-20 17:53:22.667 | SqlRunner       | Test worker    | INFO : SQL:    CREATE VIEW databaseversion_master AS SELECT dbv.*, vc.logicaltime as client_version FROM databaseversion dbv JOIN databaseversion_vectorclock vc on dbv.id=vc.databaseversion_id and dbv.client=vc.client WHERE dbv.status='MASTER'; 
29-3-20 17:53:22.669 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master AS SELECT fv0.* FROM fileversion fv0 JOIN databaseversion dbv ON fv0.databaseversion_id=dbv.id AND dbv.status='MASTER'; 
29-3-20 17:53:22.670 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_maxversion AS SELECT DISTINCT filehistory_id, MAX(version) version FROM fileversion_master GROUP BY filehistory_id; 
29-3-20 17:53:22.672 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_last AS SELECT fv.* FROM fileversion_master_maxversion fvmax JOIN fileversion_master fv ON fvmax.filehistory_id=fv.filehistory_id AND fvmax.version=fv.version WHERE fv.status<>'DELETED'; 
29-3-20 17:53:22.677 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
29-3-20 17:53:22.677 | SqlRunner       | Test worker    | INFO : SQL:    create view filehistory_full as select dbv.status as databaseversion_status, dbv.localtime as databaseversion_localtime, dbv.client as databaseversion_client, dbv.vectorclock_serialized as databaseversion_vectorclock_serialized, fh.* from databaseversion dbv join filehistory fh on dbv.id=fh.databaseversion_id; 
29-3-20 17:53:22.678 | SqlRunner       | Test worker    | INFO : SQL:  create view fileversion_full as select fhf.databaseversion_status, fhf.databaseversion_localtime, fhf.databaseversion_client, fhf.databaseversion_vectorclock_serialized, fv.* from filehistory_full fhf join fileversion fv on fhf.id=fv.filehistory_id and fhf.databaseversion_id=fv.databaseversion_id; 
29-3-20 17:53:22.679 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
29-3-20 17:53:22.679 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
29-3-20 17:53:22.680 | SqlRunner       | Test worker    | INFO : SQL:     create function substr_count(haystack varchar(255), needle varchar(255)) returns integer begin atomic declare strCount integer; declare lastIndex integer;  set strCount = 0; set lastIndex = 1;  while lastIndex <> 0 do set lastIndex = locate(needle, haystack, lastIndex);  if lastIndex <> 0 then set strCount = strCount + 1; set lastIndex = lastIndex + length(needle); end if; end while;  return strCount; end; 
29-3-20 17:53:22.681 | UpOperation     | Test worker    | INFO : 
29-3-20 17:53:22.681 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
29-3-20 17:53:22.681 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:22.681 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@8bae5b1) ...
29-3-20 17:53:22.682 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:22.682 | StatusOperation | Test worker    | INFO : 
29-3-20 17:53:22.682 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-3-20 17:53:22.682 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:22.682 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:53:22.682 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@5efac007) ...
29-3-20 17:53:22.682 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-87808-client-A ...
29-3-20 17:53:22.682 | StatusOperation | Test worker    | FINE : - New file: folder1
29-3-20 17:53:22.683 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:53:22.683 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@430571c8) ...
29-3-20 17:53:22.683 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:22.683 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:22.683 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:22.683 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:53:22.683 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:22.683 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@4b0556e3) ...
29-3-20 17:53:22.684 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:22.684 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@1662ef8) ...
29-3-20 17:53:22.684 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-3-20 17:53:22.684 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1585504402575] ...
29-3-20 17:53:22.684 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1585504402575]
29-3-20 17:53:22.685 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1585504402575] ...
29-3-20 17:53:22.686 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:22.704 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-3-20 17:53:22.704 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-3-20 17:53:22.704 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@639b7c71) ...
29-3-20 17:53:22.704 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-3-20 17:53:22.704 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-200329175039872-87808-client-A/folder1
29-3-20 17:53:22.704 | Indexer         | AsyncI/syncany | FINE : - /File: folder1 (directory/symlink/0-byte-file)
29-3-20 17:53:22.705 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: folder1, FOLDER)
29-3-20 17:53:22.705 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file folder1
29-3-20 17:53:22.705 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=folder1, type=FOLDER, status=NEW, size=4096, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=null, checksum=null, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rwxrwxr-x, dosAttributes=--a-]
29-3-20 17:53:22.705 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
29-3-20 17:53:22.705 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@77a98051) ...
29-3-20 17:53:22.705 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@480043e9) ...
29-3-20 17:53:22.705 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504402704, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:22.705 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-3-20 17:53:22.705 | UpOperation     | Test worker    | INFO : Last vector clock was: ()
29-3-20 17:53:22.705 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-3-20 17:53:22.706 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A1)/T=1585504402705, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:22.706 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A1)/T=1585504402705 to file /tmp/syncanytest/syncany-200329175039872-87808-client-A/.syncany/cache/database-A-0000000001 ... 
29-3-20 17:53:22.706 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-200329175039872-87808-client-A/.syncany/cache/database-A-0000000001 ...
29-3-20 17:53:22.706 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-3-20 17:53:22.706 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-87808-client-A/.syncany/cache/database-A-0000000001 to RemoteFile[name=database-A-0000000001] ...
29-3-20 17:53:22.706 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-87808-client-A/.syncany/cache/database-A-0000000001 -> Temp. remote file: RemoteFile[name=temp-TKhQe-database-A-0000000001], final location: RemoteFile[name=database-A-0000000001]
29-3-20 17:53:22.706 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-3-20 17:53:22.707 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-3-20 17:53:22.707 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-200329175039872-87808-client-A/.syncany/cache/temp-transaction-10879205788161814624.tmp
29-3-20 17:53:22.707 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@16af5fb8) ...
29-3-20 17:53:22.707 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-5aa77d20] ...
29-3-20 17:53:22.708 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-3-20 17:53:22.708 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@69eb0c21) ...
29-3-20 17:53:22.708 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-87808-client-A/.syncany/cache/database-A-0000000001 to temp. file RemoteFile[name=temp-TKhQe-database-A-0000000001] ...
29-3-20 17:53:22.708 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-TKhQe-database-A-0000000001] to final location RemoteFile[name=database-A-0000000001] ...
29-3-20 17:53:22.708 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-5aa77d20] ...
29-3-20 17:53:22.708 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-3-20 17:53:22.708 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-3-20 17:53:22.708 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A1)/T=1585504402705) ...
29-3-20 17:53:22.709 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-3-20 17:53:22.712 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@51a6d18f) ...
29-3-20 17:53:22.719 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A1)/T=1585504402705, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:22.719 | UpOperation     | Test worker    | INFO : Committing local database.
29-3-20 17:53:22.719 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-3-20 17:53:22.720 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-3-20 17:53:22.721 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504402720, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-3-20 17:53:22.721 | UpOperation     | Test worker    | INFO : Sync up done.
29-3-20 17:53:22.725 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1585504402575] ...
29-3-20 17:53:22.728 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1585504402575]
29-3-20 17:53:22.728 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:22.728 | Cache           | Test worker    | INFO : Cache size okay (0 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:22.728 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@4cd33d6a) ...
29-3-20 17:53:22.728 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:22.729 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-87808-client-B' ...
29-3-20 17:53:22.729 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:22.729 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:22.729 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:22.729 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:22.729 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:22.729 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:22.729 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:22.729 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:22.729 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:22.729 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-87808-client-B' ...
29-3-20 17:53:22.729 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:22.729 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:22.730 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:22.730 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:22.730 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:22.730 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:22.730 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:22.730 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:22.730 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:22.730 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:22.730 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:22.730 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:22.753 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
29-3-20 17:53:22.753 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
29-3-20 17:53:22.758 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
29-3-20 17:53:22.760 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
29-3-20 17:53:22.760 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
29-3-20 17:53:22.763 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
29-3-20 17:53:22.764 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
29-3-20 17:53:22.764 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
29-3-20 17:53:22.764 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS databaseversion ( id int NOT NULL IDENTITY, status varchar(45) NOT NULL, localtime datetime NOT NULL, client varchar(45) NOT NULL, vectorclock_serialized varchar(1024) NOT NULL, UNIQUE (vectorclock_serialized) ); 
29-3-20 17:53:22.765 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  chunk ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.767 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  databaseversion_vectorclock ( databaseversion_id int NOT NULL, client varchar(45) NOT NULL, logicaltime int NOT NULL, PRIMARY KEY (databaseversion_id, client), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.770 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.772 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent_chunk ( filecontent_checksum varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, num int NOT NULL, PRIMARY KEY (filecontent_checksum, chunk_checksum, num), FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.773 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filehistory ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, PRIMARY KEY (id, databaseversion_id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.776 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  fileversion ( filehistory_id varchar(40) NOT NULL, version int NOT NULL, databaseversion_id int NOT NULL, path varchar(1024) NOT NULL, type varchar(45) NOT NULL, status varchar(45) NOT NULL, size bigint NOT NULL, lastmodified datetime NOT NULL, linktarget varchar(1024), filecontent_checksum varchar(40) DEFAULT NULL, updated datetime NOT NULL, posixperms varchar(45) DEFAULT NULL, dosattrs varchar(45) DEFAULT NULL, PRIMARY KEY (filehistory_id, version, databaseversion_id), FOREIGN KEY (filehistory_id, databaseversion_id) REFERENCES filehistory (id, databaseversion_id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.778 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.779 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_chunk ( multichunk_id varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, PRIMARY KEY (multichunk_id, chunk_checksum), FOREIGN KEY (multichunk_id) REFERENCES multichunk (id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:22.782 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_muddy ( id varchar(40) NOT NULL, machine_name varchar(255) NOT NULL, machine_version int NOT NULL, PRIMARY KEY (id) ); 
29-3-20 17:53:22.783 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  known_databases ( id int NOT NULL IDENTITY, client varchar(45) NOT NULL, filenumber int NOT NULL, UNIQUE (client, filenumber) ); 
29-3-20 17:53:22.785 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  general_settings ( key varchar(255) NOT NULL, value varchar(255) NOT NULL, PRIMARY KEY (key) ); 
29-3-20 17:53:22.786 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
29-3-20 17:53:22.786 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
29-3-20 17:53:22.787 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
29-3-20 17:53:22.789 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
29-3-20 17:53:22.792 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
29-3-20 17:53:22.794 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
29-3-20 17:53:22.795 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
29-3-20 17:53:22.796 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
29-3-20 17:53:22.798 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
29-3-20 17:53:22.798 | SqlRunner       | Test worker    | INFO : SQL:    CREATE VIEW databaseversion_master AS SELECT dbv.*, vc.logicaltime as client_version FROM databaseversion dbv JOIN databaseversion_vectorclock vc on dbv.id=vc.databaseversion_id and dbv.client=vc.client WHERE dbv.status='MASTER'; 
29-3-20 17:53:22.799 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master AS SELECT fv0.* FROM fileversion fv0 JOIN databaseversion dbv ON fv0.databaseversion_id=dbv.id AND dbv.status='MASTER'; 
29-3-20 17:53:22.801 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_maxversion AS SELECT DISTINCT filehistory_id, MAX(version) version FROM fileversion_master GROUP BY filehistory_id; 
29-3-20 17:53:22.803 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_last AS SELECT fv.* FROM fileversion_master_maxversion fvmax JOIN fileversion_master fv ON fvmax.filehistory_id=fv.filehistory_id AND fvmax.version=fv.version WHERE fv.status<>'DELETED'; 
29-3-20 17:53:22.805 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
29-3-20 17:53:22.805 | SqlRunner       | Test worker    | INFO : SQL:    create view filehistory_full as select dbv.status as databaseversion_status, dbv.localtime as databaseversion_localtime, dbv.client as databaseversion_client, dbv.vectorclock_serialized as databaseversion_vectorclock_serialized, fh.* from databaseversion dbv join filehistory fh on dbv.id=fh.databaseversion_id; 
29-3-20 17:53:22.806 | SqlRunner       | Test worker    | INFO : SQL:  create view fileversion_full as select fhf.databaseversion_status, fhf.databaseversion_localtime, fhf.databaseversion_client, fhf.databaseversion_vectorclock_serialized, fv.* from filehistory_full fhf join fileversion fv on fhf.id=fv.filehistory_id and fhf.databaseversion_id=fv.databaseversion_id; 
29-3-20 17:53:22.808 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
29-3-20 17:53:22.808 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
29-3-20 17:53:22.808 | SqlRunner       | Test worker    | INFO : SQL:     create function substr_count(haystack varchar(255), needle varchar(255)) returns integer begin atomic declare strCount integer; declare lastIndex integer;  set strCount = 0; set lastIndex = 1;  while lastIndex <> 0 do set lastIndex = locate(needle, haystack, lastIndex);  if lastIndex <> 0 then set strCount = strCount + 1; set lastIndex = lastIndex + length(needle); end if; end while;  return strCount; end; 
29-3-20 17:53:22.809 | DownOperation   | Test worker    | INFO : 
29-3-20 17:53:22.809 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
29-3-20 17:53:22.809 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:22.809 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@c83cf7c) ...
29-3-20 17:53:22.810 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:22.810 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:22.810 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:22.810 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
29-3-20 17:53:22.810 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:22.810 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@a9176bf) ...
29-3-20 17:53:22.810 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:22.811 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
29-3-20 17:53:22.811 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@51a47110) ...
29-3-20 17:53:22.811 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@6872adfd) ...
29-3-20 17:53:22.811 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1585504402730] ...
29-3-20 17:53:22.811 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1585504402730]
29-3-20 17:53:22.811 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1585504402730] ...
29-3-20 17:53:22.811 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
29-3-20 17:53:22.811 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000001 to local cache at /tmp/syncanytest/syncany-200329175039872-87808-client-B/.syncany/cache/database-A-0000000001
29-3-20 17:53:22.811 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@2d809026) ...
29-3-20 17:53:22.812 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
29-3-20 17:53:22.812 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-200329175039872-87808-client-B/.syncany/cache/database-A-0000000001 ...
29-3-20 17:53:22.813 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1585504402705
29-3-20 17:53:22.819 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-87808-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:22.820 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
29-3-20 17:53:22.820 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1585504402705], B=[]}
29-3-20 17:53:22.820 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
29-3-20 17:53:22.820 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1585504402705
29-3-20 17:53:22.820 | DatabaseReconci | Test worker    | INFO : - Winner is A with branch: 
29-3-20 17:53:22.820 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1585504402705
29-3-20 17:53:22.820 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
29-3-20 17:53:22.820 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
29-3-20 17:53:22.820 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
29-3-20 17:53:22.820 | DatabaseReconci | Test worker    | INFO : Losers Branch: []
29-3-20 17:53:22.820 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1585504402705]
29-3-20 17:53:22.820 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
29-3-20 17:53:22.820 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A1)/T=1585504402705]
29-3-20 17:53:22.820 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
29-3-20 17:53:22.820 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-200329175039872-87808-client-B/.syncany/cache/database-A-0000000001 ...
29-3-20 17:53:22.821 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1585504402705
29-3-20 17:53:22.821 | DownOperation   | Test worker    | INFO : Determine file system actions ...
29-3-20 17:53:22.822 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:22.822 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
29-3-20 17:53:22.822 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
29-3-20 17:53:22.822 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
29-3-20 17:53:22.822 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=folder1, type=FOLDER, status=NEW, size=4096, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=null, checksum=null, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rwxrwxr-x, dosAttributes=--a-]
29-3-20 17:53:22.823 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file folder1
29-3-20 17:53:22.823 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=1, path=folder1, type=FOLDER, status=NEW, size=4096, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=null, checksum=null, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rwxrwxr-x, dosAttributes=--a-] AND /tmp/syncanytest/syncany-200329175039872-87808-client-B/folder1
29-3-20 17:53:22.823 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=folder1, type=FOLDER, status=NEW, size=4096, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=null, checksum=null, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rwxrwxr-x, dosAttributes=--a-]]
29-3-20 17:53:22.823 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
29-3-20 17:53:22.823 | FileSystemActio | Test worker    | INFO :    Sorted actions:
29-3-20 17:53:22.828 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=folder1, type=FOLDER, status=NEW, size=4096, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=null, checksum=null, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rwxrwxr-x, dosAttributes=--a-]]
29-3-20 17:53:22.828 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
29-3-20 17:53:22.828 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=folder1, type=FOLDER, status=NEW, size=4096, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=null, checksum=null, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rwxrwxr-x, dosAttributes=--a-]]
29-3-20 17:53:22.829 | FileSystemActio | Test worker    | INFO :      - Creating folder at FileVersion [version=1, path=folder1, type=FOLDER, status=NEW, size=4096, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=null, checksum=null, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rwxrwxr-x, dosAttributes=--a-] ...
29-3-20 17:53:22.830 | FileSystemActio | Test worker    | INFO :      - Creating folder at /tmp/syncanytest/syncany-200329175039872-87808-client-B/folder1 ...
29-3-20 17:53:22.830 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rwxrwxr-x ...
29-3-20 17:53:22.831 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
29-3-20 17:53:22.831 | DownOperation   | Test worker    | INFO :   + Applying database version (A1)
29-3-20 17:53:22.831 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A1)/T=1585504402705, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:22.839 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1585504402730] ...
29-3-20 17:53:22.845 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1585504402730]
29-3-20 17:53:22.846 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:22.846 | Cache           | Test worker    | INFO : Cache size okay (0 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:22.846 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@67e31ba2) ...
29-3-20 17:53:22.846 | DownOperation   | Test worker    | INFO : Sync down done.
29-3-20 17:53:22.848 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:22.848 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-87808-client-A' ...
29-3-20 17:53:22.848 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:22.848 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:22.848 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:22.848 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:22.848 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:22.848 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:22.848 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:22.848 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:22.848 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:22.848 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-87808-client-A' ...
29-3-20 17:53:22.848 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:22.848 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:22.848 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:22.848 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:22.848 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:22.848 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:22.848 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:22.848 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:22.848 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:22.848 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:22.848 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:22.848 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:22.852 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:22.852 | UpOperation     | Test worker    | INFO : 
29-3-20 17:53:22.853 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
29-3-20 17:53:22.853 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:22.853 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@1270c1a) ...
29-3-20 17:53:22.853 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:22.853 | StatusOperation | Test worker    | INFO : 
29-3-20 17:53:22.853 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-3-20 17:53:22.853 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:22.853 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:53:22.853 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@12782cf6) ...
29-3-20 17:53:22.854 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-87808-client-A ...
29-3-20 17:53:22.854 | StatusOperation | Test worker    | FINE : - New file: folder1/symlink-name
29-3-20 17:53:22.854 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:53:22.855 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@20e8462f) ...
29-3-20 17:53:22.855 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:22.855 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:22.855 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:22.856 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:53:22.856 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:22.856 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@6216591f) ...
29-3-20 17:53:22.856 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:22.856 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:22.856 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@706a9236) ...
29-3-20 17:53:22.856 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-3-20 17:53:22.856 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1585504402848] ...
29-3-20 17:53:22.856 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1585504402848]
29-3-20 17:53:22.857 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1585504402848] ...
29-3-20 17:53:22.858 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:22.864 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-3-20 17:53:22.864 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-3-20 17:53:22.865 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@7752ad7b) ...
29-3-20 17:53:22.865 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-3-20 17:53:22.865 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-200329175039872-87808-client-A/folder1/symlink-name
29-3-20 17:53:22.866 | Indexer         | AsyncI/syncany | FINE : - /File: folder1/symlink-name (directory/symlink/0-byte-file)
29-3-20 17:53:22.869 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: folder1/symlink-name, SYMLINK)
29-3-20 17:53:22.869 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file folder1/symlink-name
29-3-20 17:53:22.869 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=folder1/symlink-name, type=SYMLINK, status=NEW, size=15, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=/does/not/exist, checksum=null, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rwxrwxrwx, dosAttributes=--a-]
29-3-20 17:53:22.869 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
29-3-20 17:53:22.869 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@5887b895) ...
29-3-20 17:53:22.869 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@1ad03240) ...
29-3-20 17:53:22.869 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504402865, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:22.869 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@46974a41) ...
29-3-20 17:53:22.869 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-3-20 17:53:22.870 | UpOperation     | Test worker    | INFO : Last vector clock was: (A1)
29-3-20 17:53:22.870 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-3-20 17:53:22.870 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A2)/T=1585504402870, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:22.870 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A2)/T=1585504402870 to file /tmp/syncanytest/syncany-200329175039872-87808-client-A/.syncany/cache/database-A-0000000002 ... 
29-3-20 17:53:22.870 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-200329175039872-87808-client-A/.syncany/cache/database-A-0000000002 ...
29-3-20 17:53:22.871 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-3-20 17:53:22.871 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-87808-client-A/.syncany/cache/database-A-0000000002 to RemoteFile[name=database-A-0000000002] ...
29-3-20 17:53:22.871 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-87808-client-A/.syncany/cache/database-A-0000000002 -> Temp. remote file: RemoteFile[name=temp-PKdrg-database-A-0000000002], final location: RemoteFile[name=database-A-0000000002]
29-3-20 17:53:22.871 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-3-20 17:53:22.871 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-3-20 17:53:22.873 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-200329175039872-87808-client-A/.syncany/cache/temp-transaction-3813845417948807699.tmp
29-3-20 17:53:22.873 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@72b74712) ...
29-3-20 17:53:22.873 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-1068634e] ...
29-3-20 17:53:22.873 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-3-20 17:53:22.873 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@65ea003d) ...
29-3-20 17:53:22.874 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-87808-client-A/.syncany/cache/database-A-0000000002 to temp. file RemoteFile[name=temp-PKdrg-database-A-0000000002] ...
29-3-20 17:53:22.874 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-PKdrg-database-A-0000000002] to final location RemoteFile[name=database-A-0000000002] ...
29-3-20 17:53:22.874 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-1068634e] ...
29-3-20 17:53:22.875 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-3-20 17:53:22.875 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-3-20 17:53:22.875 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A2)/T=1585504402870) ...
29-3-20 17:53:22.875 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-3-20 17:53:22.877 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-3-20 17:53:22.886 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A2)/T=1585504402870, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:22.886 | UpOperation     | Test worker    | INFO : Committing local database.
29-3-20 17:53:22.886 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-3-20 17:53:22.886 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504402877, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-3-20 17:53:22.886 | UpOperation     | Test worker    | INFO : Sync up done.
29-3-20 17:53:22.888 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1585504402848] ...
29-3-20 17:53:22.892 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1585504402848]
29-3-20 17:53:22.892 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:22.892 | Cache           | Test worker    | INFO : Cache size okay (1 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:22.892 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@67188a51) ...
29-3-20 17:53:22.893 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:22.893 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-87808-client-B' ...
29-3-20 17:53:22.893 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:22.893 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:22.893 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:22.893 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:22.894 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:22.894 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:22.894 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:22.894 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:22.894 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:22.894 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-87808-client-B' ...
29-3-20 17:53:22.894 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:22.894 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:22.894 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:22.894 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:22.894 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:22.894 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:22.894 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:22.894 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:22.894 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:22.894 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:22.894 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:22.894 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:22.900 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:22.900 | DownOperation   | Test worker    | INFO : 
29-3-20 17:53:22.900 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
29-3-20 17:53:22.900 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:22.900 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@25f5c8dc) ...
29-3-20 17:53:22.900 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:22.901 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:22.902 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:22.902 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
29-3-20 17:53:22.902 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:22.902 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@68bb46d7) ...
29-3-20 17:53:22.902 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:22.902 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
29-3-20 17:53:22.902 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
29-3-20 17:53:22.902 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@400a6437) ...
29-3-20 17:53:22.902 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@1b3cf62f) ...
29-3-20 17:53:22.902 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1585504402894] ...
29-3-20 17:53:22.902 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1585504402894]
29-3-20 17:53:22.908 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1585504402894] ...
29-3-20 17:53:22.911 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
29-3-20 17:53:22.911 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000002 to local cache at /tmp/syncanytest/syncany-200329175039872-87808-client-B/.syncany/cache/database-A-0000000002
29-3-20 17:53:22.911 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@66e0a3ea) ...
29-3-20 17:53:22.912 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
29-3-20 17:53:22.912 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-200329175039872-87808-client-B/.syncany/cache/database-A-0000000002 ...
29-3-20 17:53:22.913 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1585504402870
29-3-20 17:53:22.916 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-87808-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:22.916 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-87808-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:22.916 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
29-3-20 17:53:22.917 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A2)/T=1585504402870], B=[A/(A1)/T=1585504402705]}
29-3-20 17:53:22.917 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
29-3-20 17:53:22.917 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1585504402705
29-3-20 17:53:22.917 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1585504402870
29-3-20 17:53:22.917 | DatabaseReconci | Test worker    | INFO : - Winner is A with branch: 
29-3-20 17:53:22.917 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1585504402705
29-3-20 17:53:22.917 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1585504402870
29-3-20 17:53:22.917 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
29-3-20 17:53:22.917 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
29-3-20 17:53:22.917 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
29-3-20 17:53:22.917 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1585504402705]
29-3-20 17:53:22.917 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1585504402705, A/(A2)/T=1585504402870]
29-3-20 17:53:22.917 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
29-3-20 17:53:22.917 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A2)/T=1585504402870]
29-3-20 17:53:22.917 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
29-3-20 17:53:22.917 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-200329175039872-87808-client-B/.syncany/cache/database-A-0000000002 ...
29-3-20 17:53:22.918 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1585504402870
29-3-20 17:53:22.920 | DownOperation   | Test worker    | INFO : Determine file system actions ...
29-3-20 17:53:22.920 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:22.921 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
29-3-20 17:53:22.924 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
29-3-20 17:53:22.924 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
29-3-20 17:53:22.924 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=folder1/symlink-name, type=SYMLINK, status=NEW, size=15, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=/does/not/exist, checksum=null, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rwxrwxrwx, dosAttributes=--a-]
29-3-20 17:53:22.924 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file folder1/symlink-name
29-3-20 17:53:22.924 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=1, path=folder1/symlink-name, type=SYMLINK, status=NEW, size=15, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=/does/not/exist, checksum=null, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rwxrwxrwx, dosAttributes=--a-] AND /tmp/syncanytest/syncany-200329175039872-87808-client-B/folder1/symlink-name
29-3-20 17:53:22.924 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=folder1/symlink-name, type=SYMLINK, status=NEW, size=15, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=/does/not/exist, checksum=null, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rwxrwxrwx, dosAttributes=--a-]]
29-3-20 17:53:22.924 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
29-3-20 17:53:22.925 | FileSystemActio | Test worker    | INFO :    Sorted actions:
29-3-20 17:53:22.925 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=folder1/symlink-name, type=SYMLINK, status=NEW, size=15, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=/does/not/exist, checksum=null, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rwxrwxrwx, dosAttributes=--a-]]
29-3-20 17:53:22.925 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
29-3-20 17:53:22.925 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=folder1/symlink-name, type=SYMLINK, status=NEW, size=15, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=/does/not/exist, checksum=null, updated=Sun Mar 29 17:53:22 UTC 2020, posixPermissions=rwxrwxrwx, dosAttributes=--a-]]
29-3-20 17:53:22.925 | FileSystemActio | Test worker    | INFO :      - Parent folder does not exist, creating /tmp/syncanytest/syncany-200329175039872-87808-client-B/folder1 ...
29-3-20 17:53:22.925 | FileSystemActio | Test worker    | INFO :      - Creating symlink at /tmp/syncanytest/syncany-200329175039872-87808-client-B/folder1/symlink-name (target: /does/not/exist) ...
29-3-20 17:53:22.925 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
29-3-20 17:53:22.925 | DownOperation   | Test worker    | INFO :   + Applying database version (A2)
29-3-20 17:53:22.925 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A2)/T=1585504402870, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:22.944 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1585504402894] ...
29-3-20 17:53:22.972 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1585504402894]
29-3-20 17:53:22.972 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:22.972 | Cache           | Test worker    | INFO : Cache size okay (1 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:22.972 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@181a844a) ...
29-3-20 17:53:22.972 | DownOperation   | Test worker    | INFO : Sync down done.
29-3-20 17:53:22.979 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:22.979 | LocalTransferMa | Test worker    | INFO : testTargetExists: Target exists.
29-3-20 17:53:22.984 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:22.985 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-69022-client-A' ...
29-3-20 17:53:22.985 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:22.985 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:22.985 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:22.985 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:22.985 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:22.985 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:22.985 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:22.985 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:22.985 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:22.985 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-69022-client-A' ...
29-3-20 17:53:22.985 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:22.985 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:22.985 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:22.985 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:22.985 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:22.985 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:22.985 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:22.985 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:22.985 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:22.985 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:22.986 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:22.986 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:23.015 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
29-3-20 17:53:23.017 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
29-3-20 17:53:23.023 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
29-3-20 17:53:23.026 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
29-3-20 17:53:23.026 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
29-3-20 17:53:23.030 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
29-3-20 17:53:23.030 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
29-3-20 17:53:23.030 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
29-3-20 17:53:23.030 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS databaseversion ( id int NOT NULL IDENTITY, status varchar(45) NOT NULL, localtime datetime NOT NULL, client varchar(45) NOT NULL, vectorclock_serialized varchar(1024) NOT NULL, UNIQUE (vectorclock_serialized) ); 
29-3-20 17:53:23.031 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  chunk ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:23.037 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  databaseversion_vectorclock ( databaseversion_id int NOT NULL, client varchar(45) NOT NULL, logicaltime int NOT NULL, PRIMARY KEY (databaseversion_id, client), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:23.039 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:23.041 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent_chunk ( filecontent_checksum varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, num int NOT NULL, PRIMARY KEY (filecontent_checksum, chunk_checksum, num), FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:23.045 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filehistory ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, PRIMARY KEY (id, databaseversion_id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:23.047 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  fileversion ( filehistory_id varchar(40) NOT NULL, version int NOT NULL, databaseversion_id int NOT NULL, path varchar(1024) NOT NULL, type varchar(45) NOT NULL, status varchar(45) NOT NULL, size bigint NOT NULL, lastmodified datetime NOT NULL, linktarget varchar(1024), filecontent_checksum varchar(40) DEFAULT NULL, updated datetime NOT NULL, posixperms varchar(45) DEFAULT NULL, dosattrs varchar(45) DEFAULT NULL, PRIMARY KEY (filehistory_id, version, databaseversion_id), FOREIGN KEY (filehistory_id, databaseversion_id) REFERENCES filehistory (id, databaseversion_id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:23.049 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:23.050 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_chunk ( multichunk_id varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, PRIMARY KEY (multichunk_id, chunk_checksum), FOREIGN KEY (multichunk_id) REFERENCES multichunk (id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:23.052 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_muddy ( id varchar(40) NOT NULL, machine_name varchar(255) NOT NULL, machine_version int NOT NULL, PRIMARY KEY (id) ); 
29-3-20 17:53:23.053 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  known_databases ( id int NOT NULL IDENTITY, client varchar(45) NOT NULL, filenumber int NOT NULL, UNIQUE (client, filenumber) ); 
29-3-20 17:53:23.054 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  general_settings ( key varchar(255) NOT NULL, value varchar(255) NOT NULL, PRIMARY KEY (key) ); 
29-3-20 17:53:23.056 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
29-3-20 17:53:23.056 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
29-3-20 17:53:23.056 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
29-3-20 17:53:23.058 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
29-3-20 17:53:23.059 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
29-3-20 17:53:23.061 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
29-3-20 17:53:23.062 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
29-3-20 17:53:23.064 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
29-3-20 17:53:23.065 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
29-3-20 17:53:23.065 | SqlRunner       | Test worker    | INFO : SQL:    CREATE VIEW databaseversion_master AS SELECT dbv.*, vc.logicaltime as client_version FROM databaseversion dbv JOIN databaseversion_vectorclock vc on dbv.id=vc.databaseversion_id and dbv.client=vc.client WHERE dbv.status='MASTER'; 
29-3-20 17:53:23.066 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master AS SELECT fv0.* FROM fileversion fv0 JOIN databaseversion dbv ON fv0.databaseversion_id=dbv.id AND dbv.status='MASTER'; 
29-3-20 17:53:23.068 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_maxversion AS SELECT DISTINCT filehistory_id, MAX(version) version FROM fileversion_master GROUP BY filehistory_id; 
29-3-20 17:53:23.070 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_last AS SELECT fv.* FROM fileversion_master_maxversion fvmax JOIN fileversion_master fv ON fvmax.filehistory_id=fv.filehistory_id AND fvmax.version=fv.version WHERE fv.status<>'DELETED'; 
29-3-20 17:53:23.071 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
29-3-20 17:53:23.072 | SqlRunner       | Test worker    | INFO : SQL:    create view filehistory_full as select dbv.status as databaseversion_status, dbv.localtime as databaseversion_localtime, dbv.client as databaseversion_client, dbv.vectorclock_serialized as databaseversion_vectorclock_serialized, fh.* from databaseversion dbv join filehistory fh on dbv.id=fh.databaseversion_id; 
29-3-20 17:53:23.073 | SqlRunner       | Test worker    | INFO : SQL:  create view fileversion_full as select fhf.databaseversion_status, fhf.databaseversion_localtime, fhf.databaseversion_client, fhf.databaseversion_vectorclock_serialized, fv.* from filehistory_full fhf join fileversion fv on fhf.id=fv.filehistory_id and fhf.databaseversion_id=fv.databaseversion_id; 
29-3-20 17:53:23.075 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
29-3-20 17:53:23.075 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
29-3-20 17:53:23.075 | SqlRunner       | Test worker    | INFO : SQL:     create function substr_count(haystack varchar(255), needle varchar(255)) returns integer begin atomic declare strCount integer; declare lastIndex integer;  set strCount = 0; set lastIndex = 1;  while lastIndex <> 0 do set lastIndex = locate(needle, haystack, lastIndex);  if lastIndex <> 0 then set strCount = strCount + 1; set lastIndex = lastIndex + length(needle); end if; end while;  return strCount; end; 
29-3-20 17:53:23.076 | UpOperation     | Test worker    | INFO : 
29-3-20 17:53:23.076 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
29-3-20 17:53:23.076 | UpOperation     | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:23.076 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@6f85edc7) ...
29-3-20 17:53:23.077 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:23.077 | StatusOperation | Test worker    | INFO : 
29-3-20 17:53:23.077 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
29-3-20 17:53:23.077 | StatusOperation | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:23.077 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
29-3-20 17:53:23.077 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@3cf6c2da) ...
29-3-20 17:53:23.078 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-200329175039872-69022-client-A ...
29-3-20 17:53:23.078 | StatusOperation | Test worker    | FINE : - New file: symlink-name
29-3-20 17:53:23.078 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
29-3-20 17:53:23.078 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@4f53538e) ...
29-3-20 17:53:23.078 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:23.078 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:23.079 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:23.079 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
29-3-20 17:53:23.079 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:23.079 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@796ab52b) ...
29-3-20 17:53:23.079 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:23.080 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@6f532134) ...
29-3-20 17:53:23.080 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
29-3-20 17:53:23.080 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1585504402986] ...
29-3-20 17:53:23.080 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1585504402986]
29-3-20 17:53:23.080 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1585504402986] ...
29-3-20 17:53:23.081 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:23.088 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
29-3-20 17:53:23.088 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
29-3-20 17:53:23.088 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@4c5a49b0) ...
29-3-20 17:53:23.088 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
29-3-20 17:53:23.088 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-200329175039872-69022-client-A/symlink-name
29-3-20 17:53:23.089 | Indexer         | AsyncI/syncany | FINE : - /File: symlink-name (directory/symlink/0-byte-file)
29-3-20 17:53:23.089 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: symlink-name, SYMLINK)
29-3-20 17:53:23.089 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file symlink-name
29-3-20 17:53:23.089 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=10, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=/etc/hosts, checksum=null, updated=Sun Mar 29 17:53:23 UTC 2020, posixPermissions=rwxrwxrwx, dosAttributes=--a-]
29-3-20 17:53:23.089 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
29-3-20 17:53:23.089 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@7e0e2e44) ...
29-3-20 17:53:23.089 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@67c1c419) ...
29-3-20 17:53:23.090 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504403088, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:23.090 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
29-3-20 17:53:23.090 | UpOperation     | Test worker    | INFO : Last vector clock was: ()
29-3-20 17:53:23.090 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
29-3-20 17:53:23.090 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A1)/T=1585504403090, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:23.090 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A1)/T=1585504403090 to file /tmp/syncanytest/syncany-200329175039872-69022-client-A/.syncany/cache/database-A-0000000001 ... 
29-3-20 17:53:23.090 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-200329175039872-69022-client-A/.syncany/cache/database-A-0000000001 ...
29-3-20 17:53:23.091 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@4fb7b1e7) ...
29-3-20 17:53:23.091 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
29-3-20 17:53:23.091 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-69022-client-A/.syncany/cache/database-A-0000000001 to RemoteFile[name=database-A-0000000001] ...
29-3-20 17:53:23.091 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-200329175039872-69022-client-A/.syncany/cache/database-A-0000000001 -> Temp. remote file: RemoteFile[name=temp-UXyIj-database-A-0000000001], final location: RemoteFile[name=database-A-0000000001]
29-3-20 17:53:23.091 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
29-3-20 17:53:23.091 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
29-3-20 17:53:23.092 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-200329175039872-69022-client-A/.syncany/cache/temp-transaction-4975424812251160630.tmp
29-3-20 17:53:23.093 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@4b766d15) ...
29-3-20 17:53:23.093 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-6449081b] ...
29-3-20 17:53:23.093 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
29-3-20 17:53:23.093 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@4644f80a) ...
29-3-20 17:53:23.093 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-200329175039872-69022-client-A/.syncany/cache/database-A-0000000001 to temp. file RemoteFile[name=temp-UXyIj-database-A-0000000001] ...
29-3-20 17:53:23.094 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-UXyIj-database-A-0000000001] to final location RemoteFile[name=database-A-0000000001] ...
29-3-20 17:53:23.094 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-6449081b] ...
29-3-20 17:53:23.095 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
29-3-20 17:53:23.095 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
29-3-20 17:53:23.095 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A1)/T=1585504403090) ...
29-3-20 17:53:23.095 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
29-3-20 17:53:23.097 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
29-3-20 17:53:23.098 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A1)/T=1585504403090, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:23.099 | UpOperation     | Test worker    | INFO : Committing local database.
29-3-20 17:53:23.099 | UpOperation     | Test worker    | FINE : Waiting for new database version.
29-3-20 17:53:23.099 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1585504403097, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
29-3-20 17:53:23.099 | UpOperation     | Test worker    | INFO : Sync up done.
29-3-20 17:53:23.100 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1585504402986] ...
29-3-20 17:53:23.104 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1585504402986]
29-3-20 17:53:23.104 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:23.104 | Cache           | Test worker    | INFO : Cache size okay (0 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:23.104 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@6432306e) ...
29-3-20 17:53:23.104 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:23.105 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:23.105 | FileVersionSqlD | Test worker    | INFO :  getFileTree(path = symlink-name, history = %, minSlash = 0, maxSlash = 0, date <= Sat Jan 01 01:01:01 UTC 2101, types = FILE, FOLDER, SYMLINK
29-3-20 17:53:23.111 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:23.111 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-69022-client-B' ...
29-3-20 17:53:23.111 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:23.111 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:23.111 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:23.111 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:23.111 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:23.111 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:23.111 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:23.112 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:23.112 | org.syncany.plu | Test worker    | FINE : Validating required fields
29-3-20 17:53:23.112 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-200329175039872-69022-client-B' ...
29-3-20 17:53:23.112 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
29-3-20 17:53:23.112 | TransferManager | Test worker    | INFO : - With feature Retriable
29-3-20 17:53:23.112 | TransferManager | Test worker    | INFO : - With feature PathAware
29-3-20 17:53:23.112 | TransferManager | Test worker    | INFO : - With feature TransactionAware
29-3-20 17:53:23.112 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
29-3-20 17:53:23.112 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
29-3-20 17:53:23.112 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
29-3-20 17:53:23.112 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
29-3-20 17:53:23.112 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
29-3-20 17:53:23.112 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
29-3-20 17:53:23.112 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
29-3-20 17:53:23.113 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
29-3-20 17:53:23.133 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
29-3-20 17:53:23.134 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
29-3-20 17:53:23.141 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
29-3-20 17:53:23.144 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
29-3-20 17:53:23.144 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
29-3-20 17:53:23.150 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
29-3-20 17:53:23.150 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
29-3-20 17:53:23.168 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
29-3-20 17:53:23.168 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS databaseversion ( id int NOT NULL IDENTITY, status varchar(45) NOT NULL, localtime datetime NOT NULL, client varchar(45) NOT NULL, vectorclock_serialized varchar(1024) NOT NULL, UNIQUE (vectorclock_serialized) ); 
29-3-20 17:53:23.170 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  chunk ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:23.172 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  databaseversion_vectorclock ( databaseversion_id int NOT NULL, client varchar(45) NOT NULL, logicaltime int NOT NULL, PRIMARY KEY (databaseversion_id, client), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:23.174 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent ( checksum varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (checksum), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:23.175 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filecontent_chunk ( filecontent_checksum varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, num int NOT NULL, PRIMARY KEY (filecontent_checksum, chunk_checksum, num), FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:23.177 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  filehistory ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, PRIMARY KEY (id, databaseversion_id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:23.179 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  fileversion ( filehistory_id varchar(40) NOT NULL, version int NOT NULL, databaseversion_id int NOT NULL, path varchar(1024) NOT NULL, type varchar(45) NOT NULL, status varchar(45) NOT NULL, size bigint NOT NULL, lastmodified datetime NOT NULL, linktarget varchar(1024), filecontent_checksum varchar(40) DEFAULT NULL, updated datetime NOT NULL, posixperms varchar(45) DEFAULT NULL, dosattrs varchar(45) DEFAULT NULL, PRIMARY KEY (filehistory_id, version, databaseversion_id), FOREIGN KEY (filehistory_id, databaseversion_id) REFERENCES filehistory (id, databaseversion_id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (filecontent_checksum) REFERENCES filecontent (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:23.180 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk ( id varchar(40) NOT NULL, databaseversion_id int NOT NULL, size bigint NOT NULL, PRIMARY KEY (id), FOREIGN KEY (databaseversion_id) REFERENCES databaseversion (id) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:23.182 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_chunk ( multichunk_id varchar(40) NOT NULL, chunk_checksum varchar(40) NOT NULL, PRIMARY KEY (multichunk_id, chunk_checksum), FOREIGN KEY (multichunk_id) REFERENCES multichunk (id) ON DELETE NO ACTION ON UPDATE NO ACTION, FOREIGN KEY (chunk_checksum) REFERENCES chunk (checksum) ON DELETE NO ACTION ON UPDATE NO ACTION ); 
29-3-20 17:53:23.184 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  multichunk_muddy ( id varchar(40) NOT NULL, machine_name varchar(255) NOT NULL, machine_version int NOT NULL, PRIMARY KEY (id) ); 
29-3-20 17:53:23.185 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  known_databases ( id int NOT NULL IDENTITY, client varchar(45) NOT NULL, filenumber int NOT NULL, UNIQUE (client, filenumber) ); 
29-3-20 17:53:23.187 | SqlRunner       | Test worker    | INFO : SQL:  CREATE CACHED TABLE IF NOT EXISTS  general_settings ( key varchar(255) NOT NULL, value varchar(255) NOT NULL, PRIMARY KEY (key) ); 
29-3-20 17:53:23.190 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
29-3-20 17:53:23.190 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
29-3-20 17:53:23.190 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
29-3-20 17:53:23.193 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
29-3-20 17:53:23.197 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
29-3-20 17:53:23.199 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
29-3-20 17:53:23.201 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
29-3-20 17:53:23.202 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
29-3-20 17:53:23.204 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
29-3-20 17:53:23.204 | SqlRunner       | Test worker    | INFO : SQL:    CREATE VIEW databaseversion_master AS SELECT dbv.*, vc.logicaltime as client_version FROM databaseversion dbv JOIN databaseversion_vectorclock vc on dbv.id=vc.databaseversion_id and dbv.client=vc.client WHERE dbv.status='MASTER'; 
29-3-20 17:53:23.206 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master AS SELECT fv0.* FROM fileversion fv0 JOIN databaseversion dbv ON fv0.databaseversion_id=dbv.id AND dbv.status='MASTER'; 
29-3-20 17:53:23.208 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_maxversion AS SELECT DISTINCT filehistory_id, MAX(version) version FROM fileversion_master GROUP BY filehistory_id; 
29-3-20 17:53:23.210 | SqlRunner       | Test worker    | INFO : SQL:  CREATE VIEW fileversion_master_last AS SELECT fv.* FROM fileversion_master_maxversion fvmax JOIN fileversion_master fv ON fvmax.filehistory_id=fv.filehistory_id AND fvmax.version=fv.version WHERE fv.status<>'DELETED'; 
29-3-20 17:53:23.212 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
29-3-20 17:53:23.212 | SqlRunner       | Test worker    | INFO : SQL:    create view filehistory_full as select dbv.status as databaseversion_status, dbv.localtime as databaseversion_localtime, dbv.client as databaseversion_client, dbv.vectorclock_serialized as databaseversion_vectorclock_serialized, fh.* from databaseversion dbv join filehistory fh on dbv.id=fh.databaseversion_id; 
29-3-20 17:53:23.214 | SqlRunner       | Test worker    | INFO : SQL:  create view fileversion_full as select fhf.databaseversion_status, fhf.databaseversion_localtime, fhf.databaseversion_client, fhf.databaseversion_vectorclock_serialized, fv.* from filehistory_full fhf join fileversion fv on fhf.id=fv.filehistory_id and fhf.databaseversion_id=fv.databaseversion_id; 
29-3-20 17:53:23.216 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
29-3-20 17:53:23.216 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
29-3-20 17:53:23.216 | SqlRunner       | Test worker    | INFO : SQL:     create function substr_count(haystack varchar(255), needle varchar(255)) returns integer begin atomic declare strCount integer; declare lastIndex integer;  set strCount = 0; set lastIndex = 1;  while lastIndex <> 0 do set lastIndex = locate(needle, haystack, lastIndex);  if lastIndex <> 0 then set strCount = strCount + 1; set lastIndex = lastIndex + length(needle); end if; end while;  return strCount; end; 
29-3-20 17:53:23.218 | DownOperation   | Test worker    | INFO : 
29-3-20 17:53:23.218 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
29-3-20 17:53:23.218 | DownOperation   | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:23.218 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@795a911b) ...
29-3-20 17:53:23.218 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
29-3-20 17:53:23.218 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:23.218 | LsRemoteOperati | Test worker    | INFO : 
29-3-20 17:53:23.218 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
29-3-20 17:53:23.218 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
29-3-20 17:53:23.218 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@1c80cfbf) ...
29-3-20 17:53:23.219 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
29-3-20 17:53:23.219 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
29-3-20 17:53:23.219 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@14ce2437) ...
29-3-20 17:53:23.219 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@3b9f8807) ...
29-3-20 17:53:23.219 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1585504403113] ...
29-3-20 17:53:23.219 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1585504403113]
29-3-20 17:53:23.219 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1585504403113] ...
29-3-20 17:53:23.219 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
29-3-20 17:53:23.219 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000001 to local cache at /tmp/syncanytest/syncany-200329175039872-69022-client-B/.syncany/cache/database-A-0000000001
29-3-20 17:53:23.219 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@70b5e32c) ...
29-3-20 17:53:23.220 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
29-3-20 17:53:23.220 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-200329175039872-69022-client-B/.syncany/cache/database-A-0000000001 ...
29-3-20 17:53:23.221 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1585504403090
29-3-20 17:53:23.221 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-200329175039872-69022-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
29-3-20 17:53:23.222 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
29-3-20 17:53:23.222 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1585504403090], B=[]}
29-3-20 17:53:23.222 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
29-3-20 17:53:23.222 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1585504403090
29-3-20 17:53:23.222 | DatabaseReconci | Test worker    | INFO : - Winner is A with branch: 
29-3-20 17:53:23.222 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1585504403090
29-3-20 17:53:23.222 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
29-3-20 17:53:23.222 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
29-3-20 17:53:23.222 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
29-3-20 17:53:23.222 | DatabaseReconci | Test worker    | INFO : Losers Branch: []
29-3-20 17:53:23.222 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1585504403090]
29-3-20 17:53:23.222 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
29-3-20 17:53:23.222 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A1)/T=1585504403090]
29-3-20 17:53:23.222 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
29-3-20 17:53:23.222 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-200329175039872-69022-client-B/.syncany/cache/database-A-0000000001 ...
29-3-20 17:53:23.223 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1585504403090
29-3-20 17:53:23.223 | DownOperation   | Test worker    | INFO : Determine file system actions ...
29-3-20 17:53:23.228 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
29-3-20 17:53:23.228 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
29-3-20 17:53:23.228 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
29-3-20 17:53:23.228 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
29-3-20 17:53:23.229 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=10, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=/etc/hosts, checksum=null, updated=Sun Mar 29 17:53:23 UTC 2020, posixPermissions=rwxrwxrwx, dosAttributes=--a-]
29-3-20 17:53:23.229 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file symlink-name
29-3-20 17:53:23.229 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=10, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=/etc/hosts, checksum=null, updated=Sun Mar 29 17:53:23 UTC 2020, posixPermissions=rwxrwxrwx, dosAttributes=--a-] AND /tmp/syncanytest/syncany-200329175039872-69022-client-B/symlink-name
29-3-20 17:53:23.229 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=10, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=/etc/hosts, checksum=null, updated=Sun Mar 29 17:53:23 UTC 2020, posixPermissions=rwxrwxrwx, dosAttributes=--a-]]
29-3-20 17:53:23.229 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
29-3-20 17:53:23.229 | FileSystemActio | Test worker    | INFO :    Sorted actions:
29-3-20 17:53:23.229 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=10, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=/etc/hosts, checksum=null, updated=Sun Mar 29 17:53:23 UTC 2020, posixPermissions=rwxrwxrwx, dosAttributes=--a-]]
29-3-20 17:53:23.229 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
29-3-20 17:53:23.229 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=symlink-name, type=SYMLINK, status=NEW, size=10, lastModified=Sun Mar 29 17:53:22 UTC 2020, linkTarget=/etc/hosts, checksum=null, updated=Sun Mar 29 17:53:23 UTC 2020, posixPermissions=rwxrwxrwx, dosAttributes=--a-]]
29-3-20 17:53:23.229 | FileSystemActio | Test worker    | INFO :      - Creating symlink at /tmp/syncanytest/syncany-200329175039872-69022-client-B/symlink-name (target: /etc/hosts) ...
29-3-20 17:53:23.229 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
29-3-20 17:53:23.229 | DownOperation   | Test worker    | INFO :   + Applying database version (A1)
29-3-20 17:53:23.229 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A1)/T=1585504403090, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
29-3-20 17:53:23.234 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1585504403113] ...
29-3-20 17:53:23.238 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1585504403113]
29-3-20 17:53:23.238 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
29-3-20 17:53:23.238 | Cache           | Test worker    | INFO : Cache size okay (0 KB), no need to clean (keep size is 500 MB)
29-3-20 17:53:23.238 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@c4f54a3) ...
29-3-20 17:53:23.238 | DownOperation   | Test worker    | INFO : Sync down done.