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

1

tests

0

failures

0

ignored

1.018s

duration

100%

successful

Tests

Test Duration Result
testEvilC 1.018s passed

Standard error

18-11-18 14:32:57.353 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:57.353 | LocalTransferMa | Test worker    | INFO : testTargetExists: Target exists.
18-11-18 14:32:57.361 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:57.362 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-A' ...
18-11-18 14:32:57.362 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:57.362 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:57.362 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:57.362 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:57.362 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:57.362 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:57.362 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:57.362 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:57.362 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:57.362 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-A' ...
18-11-18 14:32:57.362 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:57.362 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:57.362 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:32:57.362 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:32:57.362 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:57.362 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:57.362 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:57.362 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:57.362 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:57.362 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:57.362 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:32:57.362 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:32:57.378 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
18-11-18 14:32:57.378 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
18-11-18 14:32:57.393 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
18-11-18 14:32:57.396 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
18-11-18 14:32:57.396 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
18-11-18 14:32:57.401 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
18-11-18 14:32:57.401 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
18-11-18 14:32:57.402 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
18-11-18 14:32:57.402 | 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) ); 
18-11-18 14:32:57.404 | 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 ); 
18-11-18 14:32:57.406 | 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 ); 
18-11-18 14:32:57.408 | 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 ); 
18-11-18 14:32:57.410 | 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 ); 
18-11-18 14:32:57.412 | 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 ); 
18-11-18 14:32:57.414 | 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 ); 
18-11-18 14:32:57.421 | 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 ); 
18-11-18 14:32:57.423 | 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 ); 
18-11-18 14:32:57.426 | 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) ); 
18-11-18 14:32:57.428 | 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) ); 
18-11-18 14:32:57.430 | 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) ); 
18-11-18 14:32:57.432 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
18-11-18 14:32:57.432 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
18-11-18 14:32:57.432 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
18-11-18 14:32:57.435 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
18-11-18 14:32:57.436 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
18-11-18 14:32:57.441 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
18-11-18 14:32:57.443 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
18-11-18 14:32:57.445 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
18-11-18 14:32:57.447 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
18-11-18 14:32:57.447 | 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'; 
18-11-18 14:32:57.449 | 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'; 
18-11-18 14:32:57.451 | 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; 
18-11-18 14:32:57.453 | 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'; 
18-11-18 14:32:57.455 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
18-11-18 14:32:57.456 | 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; 
18-11-18 14:32:57.457 | 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; 
18-11-18 14:32:57.460 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
18-11-18 14:32:57.460 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
18-11-18 14:32:57.460 | 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; 
18-11-18 14:32:57.462 | UpOperation     | Test worker    | INFO : 
18-11-18 14:32:57.462 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
18-11-18 14:32:57.462 | UpOperation     | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.462 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@3fd1be86) ...
18-11-18 14:32:57.463 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.463 | StatusOperation | Test worker    | INFO : 
18-11-18 14:32:57.463 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
18-11-18 14:32:57.463 | StatusOperation | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.463 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
18-11-18 14:32:57.463 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
18-11-18 14:32:57.463 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@3d9bd472) ...
18-11-18 14:32:57.464 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-181118143132272-55686-client-A ...
18-11-18 14:32:57.464 | StatusOperation | Test worker    | FINE : - New file: A1
18-11-18 14:32:57.464 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
18-11-18 14:32:57.464 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@299da1e2) ...
18-11-18 14:32:57.464 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:32:57.465 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.465 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:32:57.465 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
18-11-18 14:32:57.465 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.465 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@2e55c2ba) ...
18-11-18 14:32:57.465 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:32:57.465 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@1d9cd3d2) ...
18-11-18 14:32:57.465 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
18-11-18 14:32:57.465 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1542551577362] ...
18-11-18 14:32:57.465 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1542551577362]
18-11-18 14:32:57.467 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1542551577362] ...
18-11-18 14:32:57.468 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.476 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
18-11-18 14:32:57.476 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
18-11-18 14:32:57.477 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@7e2ef0b1) ...
18-11-18 14:32:57.477 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
18-11-18 14:32:57.477 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-181118143132272-55686-client-A/A1
18-11-18 14:32:57.477 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-181118143132272-55686-client-A/A1
18-11-18 14:32:57.478 | Indexer         | AsyncI/syncany | FINE : - Chunk new: 7e96f4eeeeb332e93b30d02c1b20bd05fa911e76
18-11-18 14:32:57.478 | Indexer         | AsyncI/syncany | FINE : - +MultiChunk bebb53573800509bcf4649497b49dc01654bd0c8
18-11-18 14:32:57.479 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: 7e96f4eeeeb332e93b30d02c1b20bd05fa911e76 > bebb53573800509bcf4649497b49dc01654bd0c8
18-11-18 14:32:57.479 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 7e96f4eeeeb332e93b30d02c1b20bd05fa911e76 > /tmp/syncanytest/syncany-181118143132272-55686-client-A/A1
18-11-18 14:32:57.479 | Indexer         | AsyncI/syncany | FINE : - /File: A1 (checksum 7e96f4eeeeb332e93b30d02c1b20bd05fa911e76)
18-11-18 14:32:57.480 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: A1, checksum: 7e96f4eeeeb332e93b30d02c1b20bd05fa911e76)
18-11-18 14:32:57.480 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file A1
18-11-18 14:32:57.480 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=A1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=7e96f4eeeeb332e93b30d02c1b20bd05fa911e76, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:32:57.480 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
18-11-18 14:32:57.480 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@6bc214a0) ...
18-11-18 14:32:57.480 | Indexer         | AsyncI/syncany | FINE : - /MultiChunk bebb53573800509bcf4649497b49dc01654bd0c8
18-11-18 14:32:57.481 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@54109625) ...
18-11-18 14:32:57.481 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1542551577476, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
18-11-18 14:32:57.481 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
18-11-18 14:32:57.481 | UpOperation     | Test worker    | INFO : Last vector clock was: ()
18-11-18 14:32:57.481 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
18-11-18 14:32:57.481 | UpOperation     | Test worker    | INFO : - Uploading multichunk bebb53573800509bcf4649497b49dc01654bd0c8 from /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/multichunk-bebb53573800509bcf4649497b49dc01654bd0c8 to RemoteFile[name=multichunk-bebb53573800509bcf4649497b49dc01654bd0c8] ...
18-11-18 14:32:57.481 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/multichunk-bebb53573800509bcf4649497b49dc01654bd0c8 -> Temp. remote file: RemoteFile[name=temp-gyBOh-multichunk-bebb53573800509bcf4649497b49dc01654bd0c8], final location: RemoteFile[name=multichunk-bebb53573800509bcf4649497b49dc01654bd0c8]
18-11-18 14:32:57.481 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A1)/T=1542551577481, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
18-11-18 14:32:57.482 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A1)/T=1542551577481 to file /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-A-0000000001 ... 
18-11-18 14:32:57.482 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-A-0000000001 ...
18-11-18 14:32:57.482 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
18-11-18 14:32:57.482 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-A-0000000001 to RemoteFile[name=database-A-0000000001] ...
18-11-18 14:32:57.482 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-A-0000000001 -> Temp. remote file: RemoteFile[name=temp-XveXG-database-A-0000000001], final location: RemoteFile[name=database-A-0000000001]
18-11-18 14:32:57.483 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
18-11-18 14:32:57.483 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
18-11-18 14:32:57.485 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/temp-transaction-620336559339252265.tmp
18-11-18 14:32:57.485 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@609ac69f) ...
18-11-18 14:32:57.485 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-55f9ea01] ...
18-11-18 14:32:57.485 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
18-11-18 14:32:57.485 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@c06f94d) ...
18-11-18 14:32:57.485 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/multichunk-bebb53573800509bcf4649497b49dc01654bd0c8 to temp. file RemoteFile[name=temp-gyBOh-multichunk-bebb53573800509bcf4649497b49dc01654bd0c8] ...
18-11-18 14:32:57.486 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@a64e021) ...
18-11-18 14:32:57.486 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-A-0000000001 to temp. file RemoteFile[name=temp-XveXG-database-A-0000000001] ...
18-11-18 14:32:57.486 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-gyBOh-multichunk-bebb53573800509bcf4649497b49dc01654bd0c8] to final location RemoteFile[name=multichunk-bebb53573800509bcf4649497b49dc01654bd0c8] ...
18-11-18 14:32:57.487 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-XveXG-database-A-0000000001] to final location RemoteFile[name=database-A-0000000001] ...
18-11-18 14:32:57.487 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-55f9ea01] ...
18-11-18 14:32:57.487 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
18-11-18 14:32:57.487 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
18-11-18 14:32:57.487 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A1)/T=1542551577481) ...
18-11-18 14:32:57.488 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@505cc3b1) ...
18-11-18 14:32:57.489 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
18-11-18 14:32:57.502 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
18-11-18 14:32:57.504 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A1)/T=1542551577481, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
18-11-18 14:32:57.504 | UpOperation     | Test worker    | INFO : Committing local database.
18-11-18 14:32:57.504 | UpOperation     | Test worker    | FINE : Waiting for new database version.
18-11-18 14:32:57.504 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1542551577502, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
18-11-18 14:32:57.504 | UpOperation     | Test worker    | INFO : Sync up done.
18-11-18 14:32:57.505 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1542551577362] ...
18-11-18 14:32:57.512 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1542551577362]
18-11-18 14:32:57.512 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
18-11-18 14:32:57.512 | Cache           | Test worker    | INFO : Cache size okay (51 KB), no need to clean (keep size is 500 MB)
18-11-18 14:32:57.512 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@5d52f622) ...
18-11-18 14:32:57.513 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:57.513 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-A' ...
18-11-18 14:32:57.513 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:57.513 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:57.513 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:57.513 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:57.513 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:57.513 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:57.513 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:57.513 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:57.513 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:57.513 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-A' ...
18-11-18 14:32:57.513 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:57.513 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:57.513 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:32:57.513 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:32:57.513 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:57.513 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:57.513 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:57.513 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:57.513 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:57.513 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:57.513 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:32:57.513 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:32:57.514 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.514 | UpOperation     | Test worker    | INFO : 
18-11-18 14:32:57.514 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
18-11-18 14:32:57.514 | UpOperation     | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.514 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@ad69654) ...
18-11-18 14:32:57.515 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.515 | StatusOperation | Test worker    | INFO : 
18-11-18 14:32:57.515 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
18-11-18 14:32:57.515 | StatusOperation | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.515 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
18-11-18 14:32:57.515 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
18-11-18 14:32:57.515 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@6c5ac73f) ...
18-11-18 14:32:57.516 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-181118143132272-55686-client-A ...
18-11-18 14:32:57.516 | StatusOperation | Test worker    | FINE : - New file: A2
18-11-18 14:32:57.516 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
18-11-18 14:32:57.516 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@1a72d61c) ...
18-11-18 14:32:57.516 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:32:57.517 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.517 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:32:57.517 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
18-11-18 14:32:57.517 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.517 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@27cb23f8) ...
18-11-18 14:32:57.517 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:32:57.517 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
18-11-18 14:32:57.517 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@2a9b03ca) ...
18-11-18 14:32:57.517 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
18-11-18 14:32:57.517 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1542551577513] ...
18-11-18 14:32:57.517 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1542551577513]
18-11-18 14:32:57.518 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1542551577513] ...
18-11-18 14:32:57.518 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.527 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
18-11-18 14:32:57.527 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
18-11-18 14:32:57.527 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@244fc82b) ...
18-11-18 14:32:57.527 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
18-11-18 14:32:57.528 | Indexer         | AsyncI/syncany | FINE :   + Deleted: Adding DELETED version: FileVersion [version=2, path=A1, type=FILE, status=DELETED, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=7e96f4eeeeb332e93b30d02c1b20bd05fa911e76, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:32:57.528 | Indexer         | AsyncI/syncany | FINE :                            based on: FileVersion [version=1, path=A1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=7e96f4eeeeb332e93b30d02c1b20bd05fa911e76, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:32:57.528 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-181118143132272-55686-client-A/A2
18-11-18 14:32:57.529 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-181118143132272-55686-client-A/A2
18-11-18 14:32:57.530 | Indexer         | AsyncI/syncany | FINE : - Chunk exists: 7e96f4eeeeb332e93b30d02c1b20bd05fa911e76
18-11-18 14:32:57.530 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 7e96f4eeeeb332e93b30d02c1b20bd05fa911e76 > /tmp/syncanytest/syncany-181118143132272-55686-client-A/A2
18-11-18 14:32:57.530 | Indexer         | AsyncI/syncany | FINE : - /File: A2 (checksum 7e96f4eeeeb332e93b30d02c1b20bd05fa911e76)
18-11-18 14:32:57.531 | Indexer         | AsyncI/syncany | FINE :    * Found old file history 5d737062d5f4d489b09e27506de6fc1f81fe3862 (by checksum: 7e96f4eeeeb332e93b30d02c1b20bd05fa911e76), appending new version.
18-11-18 14:32:57.531 | FileVersionComp | AsyncI/syncany | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = A2, but actual PATH = A1, for file A1
18-11-18 14:32:57.531 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=2, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=7e96f4eeeeb332e93b30d02c1b20bd05fa911e76, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:32:57.531 | Indexer         | AsyncI/syncany | INFO :      based on file version: FileVersion [version=1, path=A1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=7e96f4eeeeb332e93b30d02c1b20bd05fa911e76, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:32:57.531 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@720f37d6) ...
18-11-18 14:32:57.531 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@59d5b8ce) ...
18-11-18 14:32:57.531 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1542551577527, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
18-11-18 14:32:57.531 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
18-11-18 14:32:57.532 | UpOperation     | Test worker    | INFO : Last vector clock was: (A1)
18-11-18 14:32:57.532 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
18-11-18 14:32:57.532 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A2)/T=1542551577532, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
18-11-18 14:32:57.532 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A2)/T=1542551577532 to file /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-A-0000000002 ... 
18-11-18 14:32:57.532 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-A-0000000002 ...
18-11-18 14:32:57.533 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
18-11-18 14:32:57.533 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-A-0000000002 to RemoteFile[name=database-A-0000000002] ...
18-11-18 14:32:57.533 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-A-0000000002 -> Temp. remote file: RemoteFile[name=temp-WYdBD-database-A-0000000002], final location: RemoteFile[name=database-A-0000000002]
18-11-18 14:32:57.533 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
18-11-18 14:32:57.533 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
18-11-18 14:32:57.534 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/temp-transaction-1369825662241039616.tmp
18-11-18 14:32:57.534 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@6d792067) ...
18-11-18 14:32:57.534 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-24cafd62] ...
18-11-18 14:32:57.535 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
18-11-18 14:32:57.535 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@ba8a990) ...
18-11-18 14:32:57.535 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-A-0000000002 to temp. file RemoteFile[name=temp-WYdBD-database-A-0000000002] ...
18-11-18 14:32:57.535 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-WYdBD-database-A-0000000002] to final location RemoteFile[name=database-A-0000000002] ...
18-11-18 14:32:57.535 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-24cafd62] ...
18-11-18 14:32:57.535 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
18-11-18 14:32:57.535 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
18-11-18 14:32:57.535 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A2)/T=1542551577532) ...
18-11-18 14:32:57.536 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
18-11-18 14:32:57.537 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@269beb2a) ...
18-11-18 14:32:57.542 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A2)/T=1542551577532, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
18-11-18 14:32:57.542 | UpOperation     | Test worker    | INFO : Committing local database.
18-11-18 14:32:57.542 | UpOperation     | Test worker    | FINE : Waiting for new database version.
18-11-18 14:32:57.544 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
18-11-18 14:32:57.544 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1542551577544, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
18-11-18 14:32:57.544 | UpOperation     | Test worker    | INFO : Sync up done.
18-11-18 14:32:57.546 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1542551577513] ...
18-11-18 14:32:57.556 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1542551577513]
18-11-18 14:32:57.556 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
18-11-18 14:32:57.556 | Cache           | Test worker    | INFO : Cache size okay (52 KB), no need to clean (keep size is 500 MB)
18-11-18 14:32:57.556 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@78e91e8b) ...
18-11-18 14:32:57.557 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:57.557 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-A' ...
18-11-18 14:32:57.557 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:57.557 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:57.557 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:57.557 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:57.557 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:57.557 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:57.557 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:57.557 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:57.557 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:57.557 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-A' ...
18-11-18 14:32:57.557 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:57.557 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:57.557 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:32:57.557 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:32:57.557 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:57.557 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:57.557 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:57.557 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:57.557 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:57.557 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:57.557 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:32:57.557 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:32:57.561 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.561 | UpOperation     | Test worker    | INFO : 
18-11-18 14:32:57.561 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
18-11-18 14:32:57.561 | UpOperation     | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.561 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@56224587) ...
18-11-18 14:32:57.562 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.562 | StatusOperation | Test worker    | INFO : 
18-11-18 14:32:57.562 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
18-11-18 14:32:57.562 | StatusOperation | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.562 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
18-11-18 14:32:57.562 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
18-11-18 14:32:57.562 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@64d73d53) ...
18-11-18 14:32:57.562 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-181118143132272-55686-client-A ...
18-11-18 14:32:57.562 | StatusOperation | Test worker    | FINE : - New file: A3
18-11-18 14:32:57.563 | FileVersionComp | Test worker    | INFO :      - [CHANGED_CHECKSUM]: Local file DIFFERS from file version, expected CHECKSUM = 7e96f4eeeeb332e93b30d02c1b20bd05fa911e76, but actual CHECKSUM = bda83c56ae557474a68309753a21bb664234b408, for file A2
18-11-18 14:32:57.563 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
18-11-18 14:32:57.564 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@72a12d15) ...
18-11-18 14:32:57.564 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:32:57.564 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.564 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:32:57.564 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
18-11-18 14:32:57.564 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.564 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@3ca0aeb7) ...
18-11-18 14:32:57.565 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:32:57.565 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
18-11-18 14:32:57.565 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
18-11-18 14:32:57.565 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@b381d62) ...
18-11-18 14:32:57.565 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
18-11-18 14:32:57.565 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1542551577557] ...
18-11-18 14:32:57.565 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1542551577557]
18-11-18 14:32:57.565 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1542551577557] ...
18-11-18 14:32:57.566 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.572 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
18-11-18 14:32:57.572 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
18-11-18 14:32:57.572 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@5bacffc6) ...
18-11-18 14:32:57.573 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
18-11-18 14:32:57.573 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-181118143132272-55686-client-A/A3
18-11-18 14:32:57.573 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-181118143132272-55686-client-A/A3
18-11-18 14:32:57.574 | Indexer         | AsyncI/syncany | FINE : - Chunk new: b24f51a4f10bdf4e2973e507bd56dd42e2e0d5eb
18-11-18 14:32:57.574 | Indexer         | AsyncI/syncany | FINE : - +MultiChunk 79261f385be7e39f5fb9478233521e6fd794346b
18-11-18 14:32:57.575 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: b24f51a4f10bdf4e2973e507bd56dd42e2e0d5eb > 79261f385be7e39f5fb9478233521e6fd794346b
18-11-18 14:32:57.575 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: b24f51a4f10bdf4e2973e507bd56dd42e2e0d5eb > /tmp/syncanytest/syncany-181118143132272-55686-client-A/A3
18-11-18 14:32:57.575 | Indexer         | AsyncI/syncany | FINE : - /File: A3 (checksum b24f51a4f10bdf4e2973e507bd56dd42e2e0d5eb)
18-11-18 14:32:57.576 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: A3, checksum: b24f51a4f10bdf4e2973e507bd56dd42e2e0d5eb)
18-11-18 14:32:57.576 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file A3
18-11-18 14:32:57.576 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=A3, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=b24f51a4f10bdf4e2973e507bd56dd42e2e0d5eb, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:32:57.576 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
18-11-18 14:32:57.576 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@4b082df6) ...
18-11-18 14:32:57.576 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-181118143132272-55686-client-A/A2
18-11-18 14:32:57.576 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-181118143132272-55686-client-A/A2
18-11-18 14:32:57.577 | Indexer         | AsyncI/syncany | FINE : - Chunk new: bda83c56ae557474a68309753a21bb664234b408
18-11-18 14:32:57.578 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: bda83c56ae557474a68309753a21bb664234b408 > 79261f385be7e39f5fb9478233521e6fd794346b
18-11-18 14:32:57.578 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: bda83c56ae557474a68309753a21bb664234b408 > /tmp/syncanytest/syncany-181118143132272-55686-client-A/A2
18-11-18 14:32:57.578 | Indexer         | AsyncI/syncany | FINE : - /File: A2 (checksum bda83c56ae557474a68309753a21bb664234b408)
18-11-18 14:32:57.578 | Indexer         | AsyncI/syncany | FINE :    * Found old file history 5d737062d5f4d489b09e27506de6fc1f81fe3862 (by path: A2), appending new version.
18-11-18 14:32:57.578 | FileVersionComp | AsyncI/syncany | INFO :      - [CHANGED_CHECKSUM]: Local file DIFFERS from file version, expected CHECKSUM = bda83c56ae557474a68309753a21bb664234b408, but actual CHECKSUM = 7e96f4eeeeb332e93b30d02c1b20bd05fa911e76, for file A2
18-11-18 14:32:57.579 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=bda83c56ae557474a68309753a21bb664234b408, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:32:57.579 | Indexer         | AsyncI/syncany | INFO :      based on file version: FileVersion [version=2, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=7e96f4eeeeb332e93b30d02c1b20bd05fa911e76, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:32:57.579 | Indexer         | AsyncI/syncany | FINE : - /MultiChunk 79261f385be7e39f5fb9478233521e6fd794346b
18-11-18 14:32:57.579 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@e519c9f) ...
18-11-18 14:32:57.579 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1542551577572, chunks=2, multiChunks=1, fileContents=2, fileHistories=2]
18-11-18 14:32:57.588 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
18-11-18 14:32:57.589 | UpOperation     | Test worker    | INFO : Last vector clock was: (A2)
18-11-18 14:32:57.589 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
18-11-18 14:32:57.589 | UpOperation     | Test worker    | INFO : - Uploading multichunk 79261f385be7e39f5fb9478233521e6fd794346b from /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/multichunk-79261f385be7e39f5fb9478233521e6fd794346b to RemoteFile[name=multichunk-79261f385be7e39f5fb9478233521e6fd794346b] ...
18-11-18 14:32:57.589 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/multichunk-79261f385be7e39f5fb9478233521e6fd794346b -> Temp. remote file: RemoteFile[name=temp-abVNp-multichunk-79261f385be7e39f5fb9478233521e6fd794346b], final location: RemoteFile[name=multichunk-79261f385be7e39f5fb9478233521e6fd794346b]
18-11-18 14:32:57.589 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A3)/T=1542551577589, chunks=2, multiChunks=1, fileContents=2, fileHistories=2]
18-11-18 14:32:57.589 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A3)/T=1542551577589 to file /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-A-0000000003 ... 
18-11-18 14:32:57.589 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-A-0000000003 ...
18-11-18 14:32:57.590 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
18-11-18 14:32:57.590 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-A-0000000003 to RemoteFile[name=database-A-0000000003] ...
18-11-18 14:32:57.590 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-A-0000000003 -> Temp. remote file: RemoteFile[name=temp-ujnHE-database-A-0000000003], final location: RemoteFile[name=database-A-0000000003]
18-11-18 14:32:57.591 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
18-11-18 14:32:57.591 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
18-11-18 14:32:57.592 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/temp-transaction-5655748902303701610.tmp
18-11-18 14:32:57.592 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@38ed8bd1) ...
18-11-18 14:32:57.592 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-201ca500] ...
18-11-18 14:32:57.592 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
18-11-18 14:32:57.592 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@e35b273) ...
18-11-18 14:32:57.592 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/multichunk-79261f385be7e39f5fb9478233521e6fd794346b to temp. file RemoteFile[name=temp-abVNp-multichunk-79261f385be7e39f5fb9478233521e6fd794346b] ...
18-11-18 14:32:57.593 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@7d40768e) ...
18-11-18 14:32:57.593 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-A-0000000003 to temp. file RemoteFile[name=temp-ujnHE-database-A-0000000003] ...
18-11-18 14:32:57.593 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-abVNp-multichunk-79261f385be7e39f5fb9478233521e6fd794346b] to final location RemoteFile[name=multichunk-79261f385be7e39f5fb9478233521e6fd794346b] ...
18-11-18 14:32:57.593 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-ujnHE-database-A-0000000003] to final location RemoteFile[name=database-A-0000000003] ...
18-11-18 14:32:57.593 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-201ca500] ...
18-11-18 14:32:57.593 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
18-11-18 14:32:57.593 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
18-11-18 14:32:57.593 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A3)/T=1542551577589) ...
18-11-18 14:32:57.595 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
18-11-18 14:32:57.596 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@6900595e) ...
18-11-18 14:32:57.599 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
18-11-18 14:32:57.601 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A3)/T=1542551577589, chunks=2, multiChunks=1, fileContents=2, fileHistories=2]
18-11-18 14:32:57.601 | UpOperation     | Test worker    | INFO : Committing local database.
18-11-18 14:32:57.601 | UpOperation     | Test worker    | FINE : Waiting for new database version.
18-11-18 14:32:57.601 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1542551577599, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
18-11-18 14:32:57.601 | UpOperation     | Test worker    | INFO : Sync up done.
18-11-18 14:32:57.603 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1542551577557] ...
18-11-18 14:32:57.612 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1542551577557]
18-11-18 14:32:57.612 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
18-11-18 14:32:57.612 | Cache           | Test worker    | INFO : Cache size okay (154 KB), no need to clean (keep size is 500 MB)
18-11-18 14:32:57.613 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@5c6f37eb) ...
18-11-18 14:32:57.613 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:57.613 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-A' ...
18-11-18 14:32:57.613 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:57.613 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:57.613 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:57.613 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:57.613 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:57.613 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:57.613 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:57.613 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:57.613 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:57.613 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-A' ...
18-11-18 14:32:57.613 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:57.613 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:57.613 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:32:57.613 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:32:57.613 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:57.613 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:57.613 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:57.613 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:57.613 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:57.613 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:57.613 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:32:57.613 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:32:57.614 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.614 | UpOperation     | Test worker    | INFO : 
18-11-18 14:32:57.614 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
18-11-18 14:32:57.614 | UpOperation     | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.614 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@773a7454) ...
18-11-18 14:32:57.615 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.615 | StatusOperation | Test worker    | INFO : 
18-11-18 14:32:57.615 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
18-11-18 14:32:57.615 | StatusOperation | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.615 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
18-11-18 14:32:57.615 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
18-11-18 14:32:57.615 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@30c6d22d) ...
18-11-18 14:32:57.616 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-181118143132272-55686-client-A ...
18-11-18 14:32:57.616 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
18-11-18 14:32:57.617 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@69bf8df2) ...
18-11-18 14:32:57.617 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:32:57.617 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.617 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:32:57.617 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
18-11-18 14:32:57.617 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.617 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@d355436) ...
18-11-18 14:32:57.618 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:32:57.618 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
18-11-18 14:32:57.618 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
18-11-18 14:32:57.618 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
18-11-18 14:32:57.618 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@4a1e8488) ...
18-11-18 14:32:57.618 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
18-11-18 14:32:57.618 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1542551577613] ...
18-11-18 14:32:57.618 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1542551577613]
18-11-18 14:32:57.618 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1542551577613] ...
18-11-18 14:32:57.619 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.619 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
18-11-18 14:32:57.619 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
18-11-18 14:32:57.619 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
18-11-18 14:32:57.620 | Indexer         | AsyncI/syncany | FINE :   + Deleted: Adding DELETED version: FileVersion [version=2, path=A3, type=FILE, status=DELETED, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=b24f51a4f10bdf4e2973e507bd56dd42e2e0d5eb, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:32:57.620 | Indexer         | AsyncI/syncany | FINE :                            based on: FileVersion [version=1, path=A3, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=b24f51a4f10bdf4e2973e507bd56dd42e2e0d5eb, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:32:57.620 | Indexer         | AsyncI/syncany | FINE : Added database version with only deletions: DatabaseVersion [header=UnknownMachine/()/T=1542551577619, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
18-11-18 14:32:57.620 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
18-11-18 14:32:57.620 | UpOperation     | Test worker    | INFO : Last vector clock was: (A3)
18-11-18 14:32:57.621 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
18-11-18 14:32:57.621 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A4)/T=1542551577621, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
18-11-18 14:32:57.621 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A4)/T=1542551577621 to file /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-A-0000000004 ... 
18-11-18 14:32:57.621 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-A-0000000004 ...
18-11-18 14:32:57.622 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
18-11-18 14:32:57.622 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-A-0000000004 to RemoteFile[name=database-A-0000000004] ...
18-11-18 14:32:57.622 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-A-0000000004 -> Temp. remote file: RemoteFile[name=temp-jnojT-database-A-0000000004], final location: RemoteFile[name=database-A-0000000004]
18-11-18 14:32:57.622 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
18-11-18 14:32:57.623 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
18-11-18 14:32:57.624 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/temp-transaction-9030143222342497897.tmp
18-11-18 14:32:57.624 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@4f67b5ed) ...
18-11-18 14:32:57.624 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-38011cb2] ...
18-11-18 14:32:57.624 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
18-11-18 14:32:57.624 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@1e983de9) ...
18-11-18 14:32:57.624 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-A-0000000004 to temp. file RemoteFile[name=temp-jnojT-database-A-0000000004] ...
18-11-18 14:32:57.625 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-jnojT-database-A-0000000004] to final location RemoteFile[name=database-A-0000000004] ...
18-11-18 14:32:57.625 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-38011cb2] ...
18-11-18 14:32:57.625 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
18-11-18 14:32:57.625 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
18-11-18 14:32:57.625 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A4)/T=1542551577621) ...
18-11-18 14:32:57.625 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
18-11-18 14:32:57.634 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
18-11-18 14:32:57.637 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A4)/T=1542551577621, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
18-11-18 14:32:57.637 | UpOperation     | Test worker    | INFO : Committing local database.
18-11-18 14:32:57.637 | UpOperation     | Test worker    | FINE : Waiting for new database version.
18-11-18 14:32:57.637 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1542551577634, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
18-11-18 14:32:57.637 | UpOperation     | Test worker    | INFO : Sync up done.
18-11-18 14:32:57.639 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1542551577613] ...
18-11-18 14:32:57.653 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1542551577613]
18-11-18 14:32:57.653 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
18-11-18 14:32:57.653 | Cache           | Test worker    | INFO : Cache size okay (155 KB), no need to clean (keep size is 500 MB)
18-11-18 14:32:57.654 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@3cf689a8) ...
18-11-18 14:32:57.654 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:57.654 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-B' ...
18-11-18 14:32:57.654 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:57.654 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:57.654 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:57.654 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:57.654 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:57.654 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:57.654 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:57.654 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:57.654 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:57.654 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-B' ...
18-11-18 14:32:57.654 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:57.654 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:57.654 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:32:57.654 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:32:57.654 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:57.654 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:57.654 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:57.654 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:57.654 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:57.654 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:57.654 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:32:57.654 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:32:57.668 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
18-11-18 14:32:57.668 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
18-11-18 14:32:57.677 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
18-11-18 14:32:57.680 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
18-11-18 14:32:57.680 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
18-11-18 14:32:57.685 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
18-11-18 14:32:57.685 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
18-11-18 14:32:57.685 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
18-11-18 14:32:57.685 | 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) ); 
18-11-18 14:32:57.687 | 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 ); 
18-11-18 14:32:57.689 | 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 ); 
18-11-18 14:32:57.691 | 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 ); 
18-11-18 14:32:57.693 | 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 ); 
18-11-18 14:32:57.695 | 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 ); 
18-11-18 14:32:57.697 | 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 ); 
18-11-18 14:32:57.699 | 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 ); 
18-11-18 14:32:57.701 | 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 ); 
18-11-18 14:32:57.703 | 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) ); 
18-11-18 14:32:57.705 | 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) ); 
18-11-18 14:32:57.707 | 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) ); 
18-11-18 14:32:57.708 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
18-11-18 14:32:57.708 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
18-11-18 14:32:57.709 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
18-11-18 14:32:57.711 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
18-11-18 14:32:57.713 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
18-11-18 14:32:57.714 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
18-11-18 14:32:57.716 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
18-11-18 14:32:57.718 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
18-11-18 14:32:57.719 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
18-11-18 14:32:57.719 | 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'; 
18-11-18 14:32:57.722 | 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'; 
18-11-18 14:32:57.724 | 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; 
18-11-18 14:32:57.726 | 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'; 
18-11-18 14:32:57.728 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
18-11-18 14:32:57.728 | 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; 
18-11-18 14:32:57.730 | 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; 
18-11-18 14:32:57.732 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
18-11-18 14:32:57.732 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
18-11-18 14:32:57.732 | 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; 
18-11-18 14:32:57.734 | DownOperation   | Test worker    | INFO : 
18-11-18 14:32:57.734 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
18-11-18 14:32:57.734 | DownOperation   | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.734 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@31dec8fc) ...
18-11-18 14:32:57.734 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:32:57.735 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.735 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:32:57.735 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
18-11-18 14:32:57.735 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.735 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@21829df2) ...
18-11-18 14:32:57.735 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:32:57.735 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is new.
18-11-18 14:32:57.735 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
18-11-18 14:32:57.735 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is new.
18-11-18 14:32:57.735 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
18-11-18 14:32:57.735 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@31e00576) ...
18-11-18 14:32:57.735 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@3f395d60) ...
18-11-18 14:32:57.735 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1542551577654] ...
18-11-18 14:32:57.735 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1542551577654]
18-11-18 14:32:57.736 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1542551577654] ...
18-11-18 14:32:57.736 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
18-11-18 14:32:57.736 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000004 to local cache at /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/database-A-0000000004
18-11-18 14:32:57.736 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@38f52b21) ...
18-11-18 14:32:57.736 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000002 to local cache at /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/database-A-0000000002
18-11-18 14:32:57.736 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@4dd2b302) ...
18-11-18 14:32:57.737 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000003 to local cache at /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/database-A-0000000003
18-11-18 14:32:57.737 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@4e63f23a) ...
18-11-18 14:32:57.737 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000001 to local cache at /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/database-A-0000000001
18-11-18 14:32:57.737 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@3db98e69) ...
18-11-18 14:32:57.737 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
18-11-18 14:32:57.737 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/database-A-0000000001 ...
18-11-18 14:32:57.739 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1542551577481
18-11-18 14:32:57.740 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/database-A-0000000002 ...
18-11-18 14:32:57.744 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1542551577532
18-11-18 14:32:57.744 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/database-A-0000000003 ...
18-11-18 14:32:57.746 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A3)/T=1542551577589
18-11-18 14:32:57.747 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/database-A-0000000004 ...
18-11-18 14:32:57.748 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A4)/T=1542551577621
18-11-18 14:32:57.748 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:57.749 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:57.749 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:57.749 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:57.749 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
18-11-18 14:32:57.749 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1542551577481, A/(A2)/T=1542551577532, A/(A3)/T=1542551577589, A/(A4)/T=1542551577621], B=[]}
18-11-18 14:32:57.749 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
18-11-18 14:32:57.750 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1542551577481
18-11-18 14:32:57.750 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1542551577532
18-11-18 14:32:57.750 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3)/T=1542551577589
18-11-18 14:32:57.750 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A4)/T=1542551577621
18-11-18 14:32:57.750 | DatabaseReconci | Test worker    | INFO : - Winner is A with branch: 
18-11-18 14:32:57.750 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1542551577481
18-11-18 14:32:57.750 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1542551577532
18-11-18 14:32:57.750 | DatabaseReconci | Test worker    | INFO :   + A/(A3)/T=1542551577589
18-11-18 14:32:57.750 | DatabaseReconci | Test worker    | INFO :   + A/(A4)/T=1542551577621
18-11-18 14:32:57.750 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
18-11-18 14:32:57.750 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
18-11-18 14:32:57.750 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
18-11-18 14:32:57.750 | DatabaseReconci | Test worker    | INFO : Losers Branch: []
18-11-18 14:32:57.750 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1542551577481, A/(A2)/T=1542551577532, A/(A3)/T=1542551577589, A/(A4)/T=1542551577621]
18-11-18 14:32:57.750 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
18-11-18 14:32:57.750 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A1)/T=1542551577481, A/(A2)/T=1542551577532, A/(A3)/T=1542551577589, A/(A4)/T=1542551577621]
18-11-18 14:32:57.750 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
18-11-18 14:32:57.750 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/database-A-0000000001 ...
18-11-18 14:32:57.751 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1542551577481
18-11-18 14:32:57.751 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/database-A-0000000002 ...
18-11-18 14:32:57.752 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1542551577532
18-11-18 14:32:57.752 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/database-A-0000000003 ...
18-11-18 14:32:57.753 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A3)/T=1542551577589
18-11-18 14:32:57.753 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/database-A-0000000004 ...
18-11-18 14:32:57.754 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A4)/T=1542551577621
18-11-18 14:32:57.754 | DownOperation   | Test worker    | INFO : Determine file system actions ...
18-11-18 14:32:57.755 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.755 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
18-11-18 14:32:57.755 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
18-11-18 14:32:57.755 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
18-11-18 14:32:57.755 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=2, path=A3, type=FILE, status=DELETED, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=b24f51a4f10bdf4e2973e507bd56dd42e2e0d5eb, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:32:57.755 | FileVersionComp | Test worker    | INFO :      - []: Local file does not exist, and expected file was deleted, for file A3
18-11-18 14:32:57.755 | FileSystemActio | Test worker    | INFO :      -> (1) Equals: Nothing to do, winning version equals winning file: FileVersion [version=2, path=A3, type=FILE, status=DELETED, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=b24f51a4f10bdf4e2973e507bd56dd42e2e0d5eb, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-181118143132272-55686-client-B/A3
18-11-18 14:32:57.755 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
18-11-18 14:32:57.755 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=bda83c56ae557474a68309753a21bb664234b408, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:32:57.755 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file A2
18-11-18 14:32:57.755 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=bda83c56ae557474a68309753a21bb664234b408, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-181118143132272-55686-client-B/A2
18-11-18 14:32:57.756 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=bda83c56ae557474a68309753a21bb664234b408, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
18-11-18 14:32:57.756 | DownOperation   | Test worker    | INFO :   + Adding multichunk 79261f385be7e39f5fb9478233521e6fd794346b to download list ...
18-11-18 14:32:57.756 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
18-11-18 14:32:57.756 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@68e3457) ...
18-11-18 14:32:57.756 | Downloader      | Test worker    | INFO :   + Downloading multichunk 79261f385be7e39f5fb9478233521e6fd794346b ...
18-11-18 14:32:57.757 | Downloader      | Test worker    | INFO :   + Decrypting multichunk 79261f385be7e39f5fb9478233521e6fd794346b ...
18-11-18 14:32:57.757 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk 79261f385be7e39f5fb9478233521e6fd794346b ...
18-11-18 14:32:57.769 | FileSystemActio | Test worker    | INFO :    Sorted actions:
18-11-18 14:32:57.770 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=bda83c56ae557474a68309753a21bb664234b408, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
18-11-18 14:32:57.770 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
18-11-18 14:32:57.770 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=bda83c56ae557474a68309753a21bb664234b408, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
18-11-18 14:32:57.771 | Assembler       | Test worker    | INFO :      - Creating file A2 to /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/temp-reconstructedFileVersion-6114577789347762820.tmp ...
18-11-18 14:32:57.775 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
18-11-18 14:32:57.776 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
18-11-18 14:32:57.776 | DownOperation   | Test worker    | INFO :   + Applying database version (A1)
18-11-18 14:32:57.776 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A1)/T=1542551577481, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
18-11-18 14:32:57.786 | DownOperation   | Test worker    | INFO :   + Applying database version (A2)
18-11-18 14:32:57.786 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A2)/T=1542551577532, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
18-11-18 14:32:57.787 | DownOperation   | Test worker    | INFO :   + Applying database version (A3)
18-11-18 14:32:57.787 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A3)/T=1542551577589, chunks=2, multiChunks=1, fileContents=2, fileHistories=2]
18-11-18 14:32:57.790 | DownOperation   | Test worker    | INFO :   + Applying database version (A4)
18-11-18 14:32:57.790 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A4)/T=1542551577621, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
18-11-18 14:32:57.796 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1542551577654] ...
18-11-18 14:32:57.806 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1542551577654]
18-11-18 14:32:57.806 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
18-11-18 14:32:57.806 | Cache           | Test worker    | INFO : Cache size okay (104 KB), no need to clean (keep size is 500 MB)
18-11-18 14:32:57.806 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@74a01d8a) ...
18-11-18 14:32:57.806 | DownOperation   | Test worker    | INFO : Sync down done.
18-11-18 14:32:57.811 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-181118143132272-55686-client-A/A2, but actual PATH = tmp/syncanytest/syncany-181118143132272-55686-client-B/A2, for file tmp/syncanytest/syncany-181118143132272-55686-client-B/A2
18-11-18 14:32:57.811 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:57.811 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-B' ...
18-11-18 14:32:57.811 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:57.811 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:57.812 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:57.812 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:57.812 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:57.812 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:57.812 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:57.812 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:57.812 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:57.812 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-B' ...
18-11-18 14:32:57.812 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:57.812 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:57.812 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:32:57.812 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:32:57.812 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:57.812 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:57.812 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:57.812 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:57.812 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:57.813 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:57.813 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:32:57.813 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:32:57.822 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.822 | UpOperation     | Test worker    | INFO : 
18-11-18 14:32:57.822 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client B ...
18-11-18 14:32:57.822 | UpOperation     | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.822 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@63f0f761) ...
18-11-18 14:32:57.822 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.822 | StatusOperation | Test worker    | INFO : 
18-11-18 14:32:57.823 | StatusOperation | Test worker    | INFO : Running 'Status' at client B ...
18-11-18 14:32:57.823 | StatusOperation | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.823 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
18-11-18 14:32:57.823 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@301d8228) ...
18-11-18 14:32:57.823 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-181118143132272-55686-client-B ...
18-11-18 14:32:57.823 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
18-11-18 14:32:57.824 | StatusOperation | Test worker    | FINE : - New file: A4,B1
18-11-18 14:32:57.824 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@37a28315) ...
18-11-18 14:32:57.824 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:32:57.824 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.825 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:32:57.825 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
18-11-18 14:32:57.825 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.825 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@7ba78c72) ...
18-11-18 14:32:57.825 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:32:57.826 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
18-11-18 14:32:57.826 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
18-11-18 14:32:57.826 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
18-11-18 14:32:57.826 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
18-11-18 14:32:57.826 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@54112d1c) ...
18-11-18 14:32:57.826 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
18-11-18 14:32:57.826 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-B-1542551577813] ...
18-11-18 14:32:57.826 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-B-1542551577813]
18-11-18 14:32:57.826 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-B-1542551577813] ...
18-11-18 14:32:57.828 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.832 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
18-11-18 14:32:57.832 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
18-11-18 14:32:57.833 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@616d83f2) ...
18-11-18 14:32:57.834 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
18-11-18 14:32:57.834 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-181118143132272-55686-client-B/A4,B1
18-11-18 14:32:57.834 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-181118143132272-55686-client-B/A4,B1
18-11-18 14:32:57.836 | Indexer         | AsyncI/syncany | FINE : - Chunk new: 2388a04f70c81da633fe3646d71c1f2708a84caa
18-11-18 14:32:57.836 | Indexer         | AsyncI/syncany | FINE : - +MultiChunk 6ff21d215568d9010d51ca4bfd8184293c47cf8e
18-11-18 14:32:57.837 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: 2388a04f70c81da633fe3646d71c1f2708a84caa > 6ff21d215568d9010d51ca4bfd8184293c47cf8e
18-11-18 14:32:57.840 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 2388a04f70c81da633fe3646d71c1f2708a84caa > /tmp/syncanytest/syncany-181118143132272-55686-client-B/A4,B1
18-11-18 14:32:57.840 | Indexer         | AsyncI/syncany | FINE : - /File: A4,B1 (checksum 2388a04f70c81da633fe3646d71c1f2708a84caa)
18-11-18 14:32:57.841 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: A4,B1, checksum: 2388a04f70c81da633fe3646d71c1f2708a84caa)
18-11-18 14:32:57.841 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file A4,B1
18-11-18 14:32:57.841 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=2388a04f70c81da633fe3646d71c1f2708a84caa, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:32:57.841 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
18-11-18 14:32:57.842 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@3c1ea3d7) ...
18-11-18 14:32:57.842 | Indexer         | AsyncI/syncany | FINE : - /MultiChunk 6ff21d215568d9010d51ca4bfd8184293c47cf8e
18-11-18 14:32:57.842 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@1072fb3c) ...
18-11-18 14:32:57.842 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1542551577833, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
18-11-18 14:32:57.842 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@40ec85cf) ...
18-11-18 14:32:57.843 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
18-11-18 14:32:57.843 | UpOperation     | Test worker    | INFO : Last vector clock was: (A4)
18-11-18 14:32:57.843 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
18-11-18 14:32:57.843 | UpOperation     | Test worker    | INFO : - Uploading multichunk 6ff21d215568d9010d51ca4bfd8184293c47cf8e from /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/multichunk-6ff21d215568d9010d51ca4bfd8184293c47cf8e to RemoteFile[name=multichunk-6ff21d215568d9010d51ca4bfd8184293c47cf8e] ...
18-11-18 14:32:57.843 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/multichunk-6ff21d215568d9010d51ca4bfd8184293c47cf8e -> Temp. remote file: RemoteFile[name=temp-iQtLm-multichunk-6ff21d215568d9010d51ca4bfd8184293c47cf8e], final location: RemoteFile[name=multichunk-6ff21d215568d9010d51ca4bfd8184293c47cf8e]
18-11-18 14:32:57.843 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=B/(A4,B1)/T=1542551577843, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
18-11-18 14:32:57.844 | UpOperation     | Test worker    | INFO : Saving local delta database, version B/(A4,B1)/T=1542551577843 to file /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/database-B-0000000001 ... 
18-11-18 14:32:57.844 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/database-B-0000000001 ...
18-11-18 14:32:57.845 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
18-11-18 14:32:57.845 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/database-B-0000000001 to RemoteFile[name=database-B-0000000001] ...
18-11-18 14:32:57.845 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/database-B-0000000001 -> Temp. remote file: RemoteFile[name=temp-cUyup-database-B-0000000001], final location: RemoteFile[name=database-B-0000000001]
18-11-18 14:32:57.845 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
18-11-18 14:32:57.845 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
18-11-18 14:32:57.848 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/temp-transaction-8620050599321645169.tmp
18-11-18 14:32:57.848 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@195cd742) ...
18-11-18 14:32:57.848 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-4a02ac17] ...
18-11-18 14:32:57.848 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
18-11-18 14:32:57.848 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@726b3f7f) ...
18-11-18 14:32:57.849 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/multichunk-6ff21d215568d9010d51ca4bfd8184293c47cf8e to temp. file RemoteFile[name=temp-iQtLm-multichunk-6ff21d215568d9010d51ca4bfd8184293c47cf8e] ...
18-11-18 14:32:57.850 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@25032c0b) ...
18-11-18 14:32:57.850 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/database-B-0000000001 to temp. file RemoteFile[name=temp-cUyup-database-B-0000000001] ...
18-11-18 14:32:57.850 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-iQtLm-multichunk-6ff21d215568d9010d51ca4bfd8184293c47cf8e] to final location RemoteFile[name=multichunk-6ff21d215568d9010d51ca4bfd8184293c47cf8e] ...
18-11-18 14:32:57.850 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-cUyup-database-B-0000000001] to final location RemoteFile[name=database-B-0000000001] ...
18-11-18 14:32:57.850 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-4a02ac17] ...
18-11-18 14:32:57.850 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
18-11-18 14:32:57.851 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
18-11-18 14:32:57.851 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
18-11-18 14:32:57.851 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version B/(A4,B1)/T=1542551577843) ...
18-11-18 14:32:57.853 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
18-11-18 14:32:57.857 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=B/(A4,B1)/T=1542551577843, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
18-11-18 14:32:57.858 | UpOperation     | Test worker    | INFO : Committing local database.
18-11-18 14:32:57.858 | UpOperation     | Test worker    | FINE : Waiting for new database version.
18-11-18 14:32:57.858 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1542551577850, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
18-11-18 14:32:57.858 | UpOperation     | Test worker    | INFO : Sync up done.
18-11-18 14:32:57.860 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-B-1542551577813] ...
18-11-18 14:32:57.864 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-B-1542551577813]
18-11-18 14:32:57.864 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
18-11-18 14:32:57.864 | Cache           | Test worker    | INFO : Cache size okay (156 KB), no need to clean (keep size is 500 MB)
18-11-18 14:32:57.865 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@204e6076) ...
18-11-18 14:32:57.865 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:57.865 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-C' ...
18-11-18 14:32:57.865 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:57.865 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:57.865 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:57.865 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:57.865 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:57.865 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:57.865 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:57.865 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:57.865 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:57.866 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-C' ...
18-11-18 14:32:57.866 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:57.866 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:57.866 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:32:57.866 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:32:57.866 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:57.866 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:57.866 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:57.866 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:57.866 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:57.866 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:57.866 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:32:57.866 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:32:57.880 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
18-11-18 14:32:57.881 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
18-11-18 14:32:57.887 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
18-11-18 14:32:57.893 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
18-11-18 14:32:57.893 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
18-11-18 14:32:57.898 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
18-11-18 14:32:57.898 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
18-11-18 14:32:57.898 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
18-11-18 14:32:57.898 | 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) ); 
18-11-18 14:32:57.901 | 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 ); 
18-11-18 14:32:57.903 | 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 ); 
18-11-18 14:32:57.906 | 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 ); 
18-11-18 14:32:57.908 | 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 ); 
18-11-18 14:32:57.909 | 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 ); 
18-11-18 14:32:57.911 | 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 ); 
18-11-18 14:32:57.913 | 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 ); 
18-11-18 14:32:57.915 | 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 ); 
18-11-18 14:32:57.917 | 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) ); 
18-11-18 14:32:57.919 | 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) ); 
18-11-18 14:32:57.921 | 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) ); 
18-11-18 14:32:57.922 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
18-11-18 14:32:57.922 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
18-11-18 14:32:57.923 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
18-11-18 14:32:57.925 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
18-11-18 14:32:57.927 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
18-11-18 14:32:57.928 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
18-11-18 14:32:57.930 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
18-11-18 14:32:57.932 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
18-11-18 14:32:57.933 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
18-11-18 14:32:57.933 | 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'; 
18-11-18 14:32:57.936 | 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'; 
18-11-18 14:32:57.938 | 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; 
18-11-18 14:32:57.941 | 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'; 
18-11-18 14:32:57.943 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
18-11-18 14:32:57.943 | 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; 
18-11-18 14:32:57.945 | 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; 
18-11-18 14:32:57.947 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
18-11-18 14:32:57.947 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
18-11-18 14:32:57.947 | 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; 
18-11-18 14:32:57.949 | UpOperation     | Test worker    | INFO : 
18-11-18 14:32:57.950 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client C ...
18-11-18 14:32:57.950 | UpOperation     | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.950 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@3a02fdd0) ...
18-11-18 14:32:57.950 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.950 | StatusOperation | Test worker    | INFO : 
18-11-18 14:32:57.950 | StatusOperation | Test worker    | INFO : Running 'Status' at client C ...
18-11-18 14:32:57.950 | StatusOperation | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.950 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
18-11-18 14:32:57.950 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@c5bdbde) ...
18-11-18 14:32:57.951 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-181118143132272-55686-client-C ...
18-11-18 14:32:57.951 | StatusOperation | Test worker    | FINE : - New file: C1
18-11-18 14:32:57.951 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
18-11-18 14:32:57.951 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@167b390a) ...
18-11-18 14:32:57.951 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:32:57.952 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.952 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:32:57.952 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
18-11-18 14:32:57.952 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.952 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@818b4d7) ...
18-11-18 14:32:57.953 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:32:57.953 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is new.
18-11-18 14:32:57.953 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
18-11-18 14:32:57.953 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is new.
18-11-18 14:32:57.953 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
18-11-18 14:32:57.953 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is new.
18-11-18 14:32:57.953 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@2c63b258) ...
18-11-18 14:32:57.953 | UpOperation     | Test worker    | INFO : There are remote changes. Call 'down' first or use --force-upload you must, Luke!
18-11-18 14:32:57.953 | UpOperation     | Test worker    | FINE : Unknown remote databases are: [RemoteFile[name=database-A-0000000004], RemoteFile[name=database-A-0000000002], RemoteFile[name=database-A-0000000003], RemoteFile[name=database-A-0000000001], RemoteFile[name=database-B-0000000001]]
18-11-18 14:32:57.953 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@284b28a5) ...
18-11-18 14:32:57.953 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:57.953 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-C' ...
18-11-18 14:32:57.953 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:57.953 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:57.953 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:57.953 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:57.953 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:57.953 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:57.953 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:57.953 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:57.953 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:57.954 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-C' ...
18-11-18 14:32:57.954 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:57.954 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:57.954 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:32:57.954 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:32:57.954 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:57.954 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:57.954 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:57.954 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:57.954 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:57.954 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:57.954 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:32:57.954 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:32:57.965 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.965 | UpOperation     | Test worker    | INFO : 
18-11-18 14:32:57.965 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client C ...
18-11-18 14:32:57.965 | UpOperation     | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.965 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@7d1d1abc) ...
18-11-18 14:32:57.966 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.966 | StatusOperation | Test worker    | INFO : 
18-11-18 14:32:57.966 | StatusOperation | Test worker    | INFO : Running 'Status' at client C ...
18-11-18 14:32:57.966 | StatusOperation | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.966 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
18-11-18 14:32:57.966 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@3d22910b) ...
18-11-18 14:32:57.966 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-181118143132272-55686-client-C ...
18-11-18 14:32:57.967 | StatusOperation | Test worker    | FINE : - New file: C1
18-11-18 14:32:57.967 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
18-11-18 14:32:57.967 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@33056b2f) ...
18-11-18 14:32:57.967 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:32:57.967 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.967 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:32:57.967 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
18-11-18 14:32:57.967 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.967 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@14d16e37) ...
18-11-18 14:32:57.968 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:32:57.968 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is new.
18-11-18 14:32:57.968 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
18-11-18 14:32:57.968 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is new.
18-11-18 14:32:57.968 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
18-11-18 14:32:57.968 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is new.
18-11-18 14:32:57.968 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@33766393) ...
18-11-18 14:32:57.968 | UpOperation     | Test worker    | INFO : There are remote changes. Call 'down' first or use --force-upload you must, Luke!
18-11-18 14:32:57.968 | UpOperation     | Test worker    | FINE : Unknown remote databases are: [RemoteFile[name=database-A-0000000004], RemoteFile[name=database-A-0000000002], RemoteFile[name=database-A-0000000003], RemoteFile[name=database-A-0000000001], RemoteFile[name=database-B-0000000001]]
18-11-18 14:32:57.968 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@10f873e9) ...
18-11-18 14:32:57.968 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:57.968 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-C' ...
18-11-18 14:32:57.968 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:57.968 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:57.968 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:57.968 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:57.968 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:57.969 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:57.969 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:57.969 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:57.969 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:57.969 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-C' ...
18-11-18 14:32:57.969 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:57.969 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:57.969 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:32:57.969 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:32:57.969 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:57.969 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:57.969 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:57.969 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:57.969 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:57.969 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:57.969 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:32:57.969 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:32:57.976 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.976 | UpOperation     | Test worker    | INFO : 
18-11-18 14:32:57.976 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client C ...
18-11-18 14:32:57.976 | UpOperation     | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.976 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@35818b47) ...
18-11-18 14:32:57.977 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.977 | StatusOperation | Test worker    | INFO : 
18-11-18 14:32:57.977 | StatusOperation | Test worker    | INFO : Running 'Status' at client C ...
18-11-18 14:32:57.977 | StatusOperation | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.977 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
18-11-18 14:32:57.977 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@665f46f0) ...
18-11-18 14:32:57.977 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-181118143132272-55686-client-C ...
18-11-18 14:32:57.978 | StatusOperation | Test worker    | FINE : - New file: C1
18-11-18 14:32:57.978 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
18-11-18 14:32:57.978 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@4ef8a059) ...
18-11-18 14:32:57.978 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:32:57.978 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.979 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:32:57.979 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
18-11-18 14:32:57.979 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.979 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@59b2dda8) ...
18-11-18 14:32:57.979 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:32:57.979 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is new.
18-11-18 14:32:57.979 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
18-11-18 14:32:57.979 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is new.
18-11-18 14:32:57.979 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
18-11-18 14:32:57.979 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is new.
18-11-18 14:32:57.979 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@7001e75a) ...
18-11-18 14:32:57.979 | UpOperation     | Test worker    | INFO : There are remote changes. Call 'down' first or use --force-upload you must, Luke!
18-11-18 14:32:57.979 | UpOperation     | Test worker    | FINE : Unknown remote databases are: [RemoteFile[name=database-A-0000000004], RemoteFile[name=database-A-0000000002], RemoteFile[name=database-A-0000000003], RemoteFile[name=database-A-0000000001], RemoteFile[name=database-B-0000000001]]
18-11-18 14:32:57.979 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@4c32ee9d) ...
18-11-18 14:32:57.979 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:57.980 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-A' ...
18-11-18 14:32:57.980 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:57.980 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:57.980 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:57.980 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:57.980 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:57.980 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:57.980 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:57.980 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:57.980 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:57.980 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-A' ...
18-11-18 14:32:57.980 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:57.980 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:57.980 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:32:57.980 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:32:57.981 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:57.981 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:57.981 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:57.981 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:57.981 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:57.981 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:57.981 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:32:57.981 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:32:57.995 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.995 | DownOperation   | Test worker    | INFO : 
18-11-18 14:32:57.995 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client A ...
18-11-18 14:32:57.995 | DownOperation   | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.995 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@7b7a578d) ...
18-11-18 14:32:57.995 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:32:57.996 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:57.996 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:32:57.996 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
18-11-18 14:32:57.996 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:57.996 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@5fa30483) ...
18-11-18 14:32:57.996 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:32:57.996 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
18-11-18 14:32:57.996 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
18-11-18 14:32:57.996 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
18-11-18 14:32:57.996 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
18-11-18 14:32:57.996 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is new.
18-11-18 14:32:57.996 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@64d5b119) ...
18-11-18 14:32:57.996 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@12b98b20) ...
18-11-18 14:32:57.996 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-A-1542551577981] ...
18-11-18 14:32:57.996 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-A-1542551577981]
18-11-18 14:32:57.997 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-A-1542551577981] ...
18-11-18 14:32:57.997 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
18-11-18 14:32:57.997 | DownOperation   | Test worker    | INFO : - Downloading database-B-0000000001 to local cache at /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-B-0000000001
18-11-18 14:32:57.997 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@340b6c0) ...
18-11-18 14:32:57.997 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
18-11-18 14:32:57.997 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-B-0000000001 ...
18-11-18 14:32:57.999 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A4,B1)/T=1542551577843
18-11-18 14:32:58.004 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:58.004 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:58.004 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:58.005 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:58.005 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:58.005 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
18-11-18 14:32:58.005 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1542551577481, A/(A2)/T=1542551577532, A/(A3)/T=1542551577589, A/(A4)/T=1542551577621], B=[B/(A4,B1)/T=1542551577843]}
18-11-18 14:32:58.005 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
18-11-18 14:32:58.005 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1542551577481
18-11-18 14:32:58.005 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1542551577532
18-11-18 14:32:58.005 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3)/T=1542551577589
18-11-18 14:32:58.005 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A4)/T=1542551577621
18-11-18 14:32:58.005 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A4,B1)/T=1542551577843
18-11-18 14:32:58.005 | DatabaseReconci | Test worker    | INFO : - Winner is B with branch: 
18-11-18 14:32:58.005 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1542551577481
18-11-18 14:32:58.005 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1542551577532
18-11-18 14:32:58.005 | DatabaseReconci | Test worker    | INFO :   + A/(A3)/T=1542551577589
18-11-18 14:32:58.005 | DatabaseReconci | Test worker    | INFO :   + A/(A4)/T=1542551577621
18-11-18 14:32:58.005 | DatabaseReconci | Test worker    | INFO :   + B/(A4,B1)/T=1542551577843
18-11-18 14:32:58.006 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
18-11-18 14:32:58.006 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
18-11-18 14:32:58.006 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
18-11-18 14:32:58.006 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1542551577481, A/(A2)/T=1542551577532, A/(A3)/T=1542551577589, A/(A4)/T=1542551577621]
18-11-18 14:32:58.006 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1542551577481, A/(A2)/T=1542551577532, A/(A3)/T=1542551577589, A/(A4)/T=1542551577621, B/(A4,B1)/T=1542551577843]
18-11-18 14:32:58.006 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
18-11-18 14:32:58.006 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [B/(A4,B1)/T=1542551577843]
18-11-18 14:32:58.006 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
18-11-18 14:32:58.006 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-B-0000000001 ...
18-11-18 14:32:58.007 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A4,B1)/T=1542551577843
18-11-18 14:32:58.007 | DownOperation   | Test worker    | INFO : Determine file system actions ...
18-11-18 14:32:58.008 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:58.009 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
18-11-18 14:32:58.009 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
18-11-18 14:32:58.009 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
18-11-18 14:32:58.009 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=2388a04f70c81da633fe3646d71c1f2708a84caa, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:32:58.009 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file A4,B1
18-11-18 14:32:58.009 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=2388a04f70c81da633fe3646d71c1f2708a84caa, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-181118143132272-55686-client-A/A4,B1
18-11-18 14:32:58.009 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=2388a04f70c81da633fe3646d71c1f2708a84caa, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
18-11-18 14:32:58.010 | DownOperation   | Test worker    | INFO :   + Adding multichunk 6ff21d215568d9010d51ca4bfd8184293c47cf8e to download list ...
18-11-18 14:32:58.010 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
18-11-18 14:32:58.010 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@4772f16a) ...
18-11-18 14:32:58.016 | Downloader      | Test worker    | INFO :   + Downloading multichunk 6ff21d215568d9010d51ca4bfd8184293c47cf8e ...
18-11-18 14:32:58.018 | Downloader      | Test worker    | INFO :   + Decrypting multichunk 6ff21d215568d9010d51ca4bfd8184293c47cf8e ...
18-11-18 14:32:58.018 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk 6ff21d215568d9010d51ca4bfd8184293c47cf8e ...
18-11-18 14:32:58.019 | FileSystemActio | Test worker    | INFO :    Sorted actions:
18-11-18 14:32:58.020 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=2388a04f70c81da633fe3646d71c1f2708a84caa, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
18-11-18 14:32:58.020 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
18-11-18 14:32:58.020 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=2388a04f70c81da633fe3646d71c1f2708a84caa, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
18-11-18 14:32:58.020 | Assembler       | Test worker    | INFO :      - Creating file A4,B1 to /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/temp-reconstructedFileVersion-6144242568292811229.tmp ...
18-11-18 14:32:58.021 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
18-11-18 14:32:58.021 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
18-11-18 14:32:58.021 | DownOperation   | Test worker    | INFO :   + Applying database version (A4,B1)
18-11-18 14:32:58.021 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=B/(A4,B1)/T=1542551577843, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
18-11-18 14:32:58.033 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-A-1542551577981] ...
18-11-18 14:32:58.040 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-A-1542551577981]
18-11-18 14:32:58.040 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
18-11-18 14:32:58.041 | Cache           | Test worker    | INFO : Cache size okay (206 KB), no need to clean (keep size is 500 MB)
18-11-18 14:32:58.041 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@2b818dac) ...
18-11-18 14:32:58.041 | DownOperation   | Test worker    | INFO : Sync down done.
18-11-18 14:32:58.045 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-181118143132272-55686-client-A/A2, but actual PATH = tmp/syncanytest/syncany-181118143132272-55686-client-B/A2, for file tmp/syncanytest/syncany-181118143132272-55686-client-B/A2
18-11-18 14:32:58.047 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-181118143132272-55686-client-A/A4,B1, but actual PATH = tmp/syncanytest/syncany-181118143132272-55686-client-B/A4,B1, for file tmp/syncanytest/syncany-181118143132272-55686-client-B/A4,B1
18-11-18 14:32:58.049 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:58.049 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-B' ...
18-11-18 14:32:58.049 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:58.049 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:58.049 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:58.049 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:58.049 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:58.049 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:58.049 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:58.050 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:58.050 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:58.050 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-B' ...
18-11-18 14:32:58.050 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:58.050 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:58.050 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:32:58.050 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:32:58.050 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:58.050 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:58.050 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:58.050 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:58.050 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:58.050 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:58.050 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:32:58.050 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:32:58.057 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:58.058 | DownOperation   | Test worker    | INFO : 
18-11-18 14:32:58.058 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
18-11-18 14:32:58.058 | DownOperation   | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:58.058 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@2c462e16) ...
18-11-18 14:32:58.058 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:32:58.058 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:58.058 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:32:58.058 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
18-11-18 14:32:58.058 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:58.058 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@17eb552c) ...
18-11-18 14:32:58.059 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:32:58.059 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
18-11-18 14:32:58.059 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
18-11-18 14:32:58.059 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
18-11-18 14:32:58.059 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
18-11-18 14:32:58.059 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
18-11-18 14:32:58.059 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@216af91f) ...
18-11-18 14:32:58.059 | DownOperation   | Test worker    | INFO : * Nothing new. Skipping down operation.
18-11-18 14:32:58.059 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@13eb5441) ...
18-11-18 14:32:58.069 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:58.084 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-C' ...
18-11-18 14:32:58.084 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:58.084 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:58.084 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:58.085 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:58.085 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:58.085 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:58.085 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:58.085 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:58.085 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:58.085 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-C' ...
18-11-18 14:32:58.085 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:58.085 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:58.085 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:32:58.085 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:32:58.085 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:58.085 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:58.085 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:58.085 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:58.086 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:58.086 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:58.086 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:32:58.086 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:32:58.094 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:58.094 | DownOperation   | Test worker    | INFO : 
18-11-18 14:32:58.094 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client C ...
18-11-18 14:32:58.094 | DownOperation   | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:58.094 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@68a3e5c8) ...
18-11-18 14:32:58.094 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:32:58.094 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:58.095 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:32:58.095 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
18-11-18 14:32:58.095 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:58.095 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@57775d11) ...
18-11-18 14:32:58.095 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:32:58.097 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is new.
18-11-18 14:32:58.097 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
18-11-18 14:32:58.097 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is new.
18-11-18 14:32:58.097 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
18-11-18 14:32:58.097 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is new.
18-11-18 14:32:58.097 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@5f9f9ea2) ...
18-11-18 14:32:58.097 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@7b1277d8) ...
18-11-18 14:32:58.097 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-C-1542551578086] ...
18-11-18 14:32:58.098 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-C-1542551578086]
18-11-18 14:32:58.098 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-C-1542551578086] ...
18-11-18 14:32:58.098 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
18-11-18 14:32:58.098 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000004 to local cache at /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/database-A-0000000004
18-11-18 14:32:58.098 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@30570615) ...
18-11-18 14:32:58.099 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000002 to local cache at /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/database-A-0000000002
18-11-18 14:32:58.099 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@58131b70) ...
18-11-18 14:32:58.099 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000003 to local cache at /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/database-A-0000000003
18-11-18 14:32:58.099 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@4f77b1ce) ...
18-11-18 14:32:58.100 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000001 to local cache at /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/database-A-0000000001
18-11-18 14:32:58.100 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@2b0f14ca) ...
18-11-18 14:32:58.100 | DownOperation   | Test worker    | INFO : - Downloading database-B-0000000001 to local cache at /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/database-B-0000000001
18-11-18 14:32:58.100 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@23e0c810) ...
18-11-18 14:32:58.100 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
18-11-18 14:32:58.100 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/database-A-0000000001 ...
18-11-18 14:32:58.102 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1542551577481
18-11-18 14:32:58.103 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/database-A-0000000002 ...
18-11-18 14:32:58.105 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1542551577532
18-11-18 14:32:58.105 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/database-A-0000000003 ...
18-11-18 14:32:58.107 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A3)/T=1542551577589
18-11-18 14:32:58.108 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/database-A-0000000004 ...
18-11-18 14:32:58.111 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A4)/T=1542551577621
18-11-18 14:32:58.111 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/database-B-0000000001 ...
18-11-18 14:32:58.113 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A4,B1)/T=1542551577843
18-11-18 14:32:58.114 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:58.114 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:58.115 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:58.115 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:58.115 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:58.115 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
18-11-18 14:32:58.115 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1542551577481, A/(A2)/T=1542551577532, A/(A3)/T=1542551577589, A/(A4)/T=1542551577621], B=[B/(A4,B1)/T=1542551577843], C=[]}
18-11-18 14:32:58.116 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
18-11-18 14:32:58.116 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1542551577481
18-11-18 14:32:58.116 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1542551577532
18-11-18 14:32:58.116 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3)/T=1542551577589
18-11-18 14:32:58.116 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A4)/T=1542551577621
18-11-18 14:32:58.116 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A4,B1)/T=1542551577843
18-11-18 14:32:58.116 | DatabaseReconci | Test worker    | INFO : - Winner is B with branch: 
18-11-18 14:32:58.117 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1542551577481
18-11-18 14:32:58.117 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1542551577532
18-11-18 14:32:58.117 | DatabaseReconci | Test worker    | INFO :   + A/(A3)/T=1542551577589
18-11-18 14:32:58.117 | DatabaseReconci | Test worker    | INFO :   + A/(A4)/T=1542551577621
18-11-18 14:32:58.117 | DatabaseReconci | Test worker    | INFO :   + B/(A4,B1)/T=1542551577843
18-11-18 14:32:58.117 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
18-11-18 14:32:58.117 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
18-11-18 14:32:58.117 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
18-11-18 14:32:58.117 | DatabaseReconci | Test worker    | INFO : Losers Branch: []
18-11-18 14:32:58.117 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1542551577481, A/(A2)/T=1542551577532, A/(A3)/T=1542551577589, A/(A4)/T=1542551577621, B/(A4,B1)/T=1542551577843]
18-11-18 14:32:58.117 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
18-11-18 14:32:58.117 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A1)/T=1542551577481, A/(A2)/T=1542551577532, A/(A3)/T=1542551577589, A/(A4)/T=1542551577621, B/(A4,B1)/T=1542551577843]
18-11-18 14:32:58.117 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
18-11-18 14:32:58.117 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/database-A-0000000001 ...
18-11-18 14:32:58.121 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1542551577481
18-11-18 14:32:58.122 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/database-A-0000000002 ...
18-11-18 14:32:58.124 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1542551577532
18-11-18 14:32:58.125 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/database-A-0000000003 ...
18-11-18 14:32:58.127 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A3)/T=1542551577589
18-11-18 14:32:58.128 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/database-A-0000000004 ...
18-11-18 14:32:58.129 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A4)/T=1542551577621
18-11-18 14:32:58.130 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/database-B-0000000001 ...
18-11-18 14:32:58.132 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A4,B1)/T=1542551577843
18-11-18 14:32:58.133 | DownOperation   | Test worker    | INFO : Determine file system actions ...
18-11-18 14:32:58.134 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:58.136 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
18-11-18 14:32:58.136 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
18-11-18 14:32:58.136 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
18-11-18 14:32:58.136 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=2, path=A3, type=FILE, status=DELETED, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=b24f51a4f10bdf4e2973e507bd56dd42e2e0d5eb, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:32:58.136 | FileVersionComp | Test worker    | INFO :      - []: Local file does not exist, and expected file was deleted, for file A3
18-11-18 14:32:58.138 | FileSystemActio | Test worker    | INFO :      -> (1) Equals: Nothing to do, winning version equals winning file: FileVersion [version=2, path=A3, type=FILE, status=DELETED, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=b24f51a4f10bdf4e2973e507bd56dd42e2e0d5eb, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-181118143132272-55686-client-C/A3
18-11-18 14:32:58.138 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
18-11-18 14:32:58.138 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=bda83c56ae557474a68309753a21bb664234b408, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:32:58.138 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file A2
18-11-18 14:32:58.139 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=bda83c56ae557474a68309753a21bb664234b408, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-181118143132272-55686-client-C/A2
18-11-18 14:32:58.139 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=bda83c56ae557474a68309753a21bb664234b408, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
18-11-18 14:32:58.139 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
18-11-18 14:32:58.139 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=2388a04f70c81da633fe3646d71c1f2708a84caa, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:32:58.139 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file A4,B1
18-11-18 14:32:58.139 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=2388a04f70c81da633fe3646d71c1f2708a84caa, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-181118143132272-55686-client-C/A4,B1
18-11-18 14:32:58.139 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=2388a04f70c81da633fe3646d71c1f2708a84caa, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
18-11-18 14:32:58.140 | DownOperation   | Test worker    | INFO :   + Adding multichunk 79261f385be7e39f5fb9478233521e6fd794346b to download list ...
18-11-18 14:32:58.140 | DownOperation   | Test worker    | INFO :   + Adding multichunk 6ff21d215568d9010d51ca4bfd8184293c47cf8e to download list ...
18-11-18 14:32:58.140 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
18-11-18 14:32:58.141 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@299db89c) ...
18-11-18 14:32:58.141 | Downloader      | Test worker    | INFO :   + Downloading multichunk 79261f385be7e39f5fb9478233521e6fd794346b ...
18-11-18 14:32:58.142 | Downloader      | Test worker    | INFO :   + Decrypting multichunk 79261f385be7e39f5fb9478233521e6fd794346b ...
18-11-18 14:32:58.142 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk 79261f385be7e39f5fb9478233521e6fd794346b ...
18-11-18 14:32:58.144 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@382baf14) ...
18-11-18 14:32:58.144 | Downloader      | Test worker    | INFO :   + Downloading multichunk 6ff21d215568d9010d51ca4bfd8184293c47cf8e ...
18-11-18 14:32:58.144 | Downloader      | Test worker    | INFO :   + Decrypting multichunk 6ff21d215568d9010d51ca4bfd8184293c47cf8e ...
18-11-18 14:32:58.145 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk 6ff21d215568d9010d51ca4bfd8184293c47cf8e ...
18-11-18 14:32:58.146 | FileSystemActio | Test worker    | INFO :    Sorted actions:
18-11-18 14:32:58.146 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=bda83c56ae557474a68309753a21bb664234b408, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
18-11-18 14:32:58.146 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=2388a04f70c81da633fe3646d71c1f2708a84caa, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
18-11-18 14:32:58.146 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
18-11-18 14:32:58.146 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=bda83c56ae557474a68309753a21bb664234b408, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
18-11-18 14:32:58.146 | Assembler       | Test worker    | INFO :      - Creating file A2 to /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/temp-reconstructedFileVersion-2899905208477915558.tmp ...
18-11-18 14:32:58.147 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
18-11-18 14:32:58.149 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=2388a04f70c81da633fe3646d71c1f2708a84caa, updated=Sun Nov 18 14:32:57 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
18-11-18 14:32:58.149 | Assembler       | Test worker    | INFO :      - Creating file A4,B1 to /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/temp-reconstructedFileVersion-5816046730309319749.tmp ...
18-11-18 14:32:58.150 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
18-11-18 14:32:58.152 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
18-11-18 14:32:58.152 | DownOperation   | Test worker    | INFO :   + Applying database version (A1)
18-11-18 14:32:58.152 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A1)/T=1542551577481, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
18-11-18 14:32:58.154 | DownOperation   | Test worker    | INFO :   + Applying database version (A2)
18-11-18 14:32:58.154 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A2)/T=1542551577532, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
18-11-18 14:32:58.156 | DownOperation   | Test worker    | INFO :   + Applying database version (A3)
18-11-18 14:32:58.156 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A3)/T=1542551577589, chunks=2, multiChunks=1, fileContents=2, fileHistories=2]
18-11-18 14:32:58.159 | DownOperation   | Test worker    | INFO :   + Applying database version (A4)
18-11-18 14:32:58.159 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A4)/T=1542551577621, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
18-11-18 14:32:58.161 | DownOperation   | Test worker    | INFO :   + Applying database version (A4,B1)
18-11-18 14:32:58.161 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=B/(A4,B1)/T=1542551577843, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
18-11-18 14:32:58.170 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-C-1542551578086] ...
18-11-18 14:32:58.174 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-C-1542551578086]
18-11-18 14:32:58.175 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
18-11-18 14:32:58.175 | Cache           | Test worker    | INFO : Cache size okay (156 KB), no need to clean (keep size is 500 MB)
18-11-18 14:32:58.175 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@4d260360) ...
18-11-18 14:32:58.175 | DownOperation   | Test worker    | INFO : Sync down done.
18-11-18 14:32:58.177 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:58.178 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-A' ...
18-11-18 14:32:58.178 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:58.178 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:58.178 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:58.178 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:58.178 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:58.178 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:58.178 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:58.178 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:58.178 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:58.178 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-A' ...
18-11-18 14:32:58.178 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:58.178 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:58.178 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:32:58.178 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:32:58.178 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:58.178 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:58.178 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:58.178 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:58.178 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:58.178 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:58.178 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:32:58.178 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:32:58.183 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:58.183 | UpOperation     | Test worker    | INFO : 
18-11-18 14:32:58.183 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
18-11-18 14:32:58.183 | UpOperation     | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:58.183 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@21c5eb12) ...
18-11-18 14:32:58.184 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:58.184 | StatusOperation | Test worker    | INFO : 
18-11-18 14:32:58.184 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
18-11-18 14:32:58.184 | StatusOperation | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:58.184 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
18-11-18 14:32:58.184 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@5f0de49a) ...
18-11-18 14:32:58.185 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-181118143132272-55686-client-A ...
18-11-18 14:32:58.185 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
18-11-18 14:32:58.185 | StatusOperation | Test worker    | INFO : - No changes to local database
18-11-18 14:32:58.185 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@182082c3) ...
18-11-18 14:32:58.185 | UpOperation     | Test worker    | INFO : Local database is up-to-date (change set). NOTHING TO DO!
18-11-18 14:32:58.185 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@622ec214) ...
18-11-18 14:32:58.185 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:58.186 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-B' ...
18-11-18 14:32:58.186 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:58.186 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:58.186 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:58.186 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:58.186 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:58.186 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:58.186 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:58.186 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:58.186 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:58.186 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-B' ...
18-11-18 14:32:58.186 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:58.186 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:58.186 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:32:58.186 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:32:58.186 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:58.187 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:58.187 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:58.187 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:58.187 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:58.187 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:58.187 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:32:58.187 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:32:58.191 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:58.191 | UpOperation     | Test worker    | INFO : 
18-11-18 14:32:58.191 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client B ...
18-11-18 14:32:58.191 | UpOperation     | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:58.191 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@285e0bae) ...
18-11-18 14:32:58.192 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:58.192 | StatusOperation | Test worker    | INFO : 
18-11-18 14:32:58.192 | StatusOperation | Test worker    | INFO : Running 'Status' at client B ...
18-11-18 14:32:58.192 | StatusOperation | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:58.192 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
18-11-18 14:32:58.192 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@205ee814) ...
18-11-18 14:32:58.193 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-181118143132272-55686-client-B ...
18-11-18 14:32:58.193 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
18-11-18 14:32:58.193 | StatusOperation | Test worker    | INFO : - No changes to local database
18-11-18 14:32:58.193 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@467320d5) ...
18-11-18 14:32:58.193 | UpOperation     | Test worker    | INFO : Local database is up-to-date (change set). NOTHING TO DO!
18-11-18 14:32:58.193 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@6ab608d0) ...
18-11-18 14:32:58.193 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:58.194 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-C' ...
18-11-18 14:32:58.194 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:58.194 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:58.194 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:58.194 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:58.194 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:58.194 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:58.194 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:58.194 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:58.194 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:58.194 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-C' ...
18-11-18 14:32:58.194 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:58.194 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:58.194 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:32:58.194 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:32:58.195 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:58.195 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:58.195 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:58.195 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:58.195 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:58.195 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:58.195 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:32:58.195 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:32:58.199 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:58.199 | UpOperation     | Test worker    | INFO : 
18-11-18 14:32:58.200 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client C ...
18-11-18 14:32:58.200 | UpOperation     | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:58.200 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@213d6374) ...
18-11-18 14:32:58.200 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:58.200 | StatusOperation | Test worker    | INFO : 
18-11-18 14:32:58.200 | StatusOperation | Test worker    | INFO : Running 'Status' at client C ...
18-11-18 14:32:58.200 | StatusOperation | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:58.201 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
18-11-18 14:32:58.201 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@243dfd84) ...
18-11-18 14:32:58.201 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-181118143132272-55686-client-C ...
18-11-18 14:32:58.202 | StatusOperation | Test worker    | FINE : - New file: C1
18-11-18 14:32:58.202 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
18-11-18 14:32:58.202 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@348da6d5) ...
18-11-18 14:32:58.202 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:32:58.203 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:58.204 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:32:58.204 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
18-11-18 14:32:58.204 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:58.204 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@16118735) ...
18-11-18 14:32:58.204 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:32:58.204 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
18-11-18 14:32:58.204 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
18-11-18 14:32:58.204 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
18-11-18 14:32:58.204 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
18-11-18 14:32:58.204 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
18-11-18 14:32:58.204 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@366b9781) ...
18-11-18 14:32:58.204 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
18-11-18 14:32:58.204 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-C-1542551578195] ...
18-11-18 14:32:58.205 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-C-1542551578195]
18-11-18 14:32:58.206 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-C-1542551578195] ...
18-11-18 14:32:58.207 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:58.212 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
18-11-18 14:32:58.212 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
18-11-18 14:32:58.213 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@335ba7cb) ...
18-11-18 14:32:58.213 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
18-11-18 14:32:58.213 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-181118143132272-55686-client-C/C1
18-11-18 14:32:58.213 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-181118143132272-55686-client-C/C1
18-11-18 14:32:58.214 | Indexer         | AsyncI/syncany | FINE : - Chunk new: 52cb4c852352454589923a722ccbc565cdaa574a
18-11-18 14:32:58.216 | Indexer         | AsyncI/syncany | FINE : - +MultiChunk a6aaceef013c1697c4a12f04b8f17a2432cae06f
18-11-18 14:32:58.217 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: 52cb4c852352454589923a722ccbc565cdaa574a > a6aaceef013c1697c4a12f04b8f17a2432cae06f
18-11-18 14:32:58.217 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 52cb4c852352454589923a722ccbc565cdaa574a > /tmp/syncanytest/syncany-181118143132272-55686-client-C/C1
18-11-18 14:32:58.217 | Indexer         | AsyncI/syncany | FINE : - /File: C1 (checksum 52cb4c852352454589923a722ccbc565cdaa574a)
18-11-18 14:32:58.219 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: C1, checksum: 52cb4c852352454589923a722ccbc565cdaa574a)
18-11-18 14:32:58.219 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file C1
18-11-18 14:32:58.220 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=52cb4c852352454589923a722ccbc565cdaa574a, updated=Sun Nov 18 14:32:58 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:32:58.220 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
18-11-18 14:32:58.220 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@267c0a2e) ...
18-11-18 14:32:58.220 | Indexer         | AsyncI/syncany | FINE : - /MultiChunk a6aaceef013c1697c4a12f04b8f17a2432cae06f
18-11-18 14:32:58.220 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@5d4d83de) ...
18-11-18 14:32:58.220 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1542551578213, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
18-11-18 14:32:58.221 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
18-11-18 14:32:58.221 | UpOperation     | Test worker    | INFO : Last vector clock was: (A4,B1)
18-11-18 14:32:58.221 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
18-11-18 14:32:58.221 | UpOperation     | Test worker    | INFO : - Uploading multichunk a6aaceef013c1697c4a12f04b8f17a2432cae06f from /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/multichunk-a6aaceef013c1697c4a12f04b8f17a2432cae06f to RemoteFile[name=multichunk-a6aaceef013c1697c4a12f04b8f17a2432cae06f] ...
18-11-18 14:32:58.221 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/multichunk-a6aaceef013c1697c4a12f04b8f17a2432cae06f -> Temp. remote file: RemoteFile[name=temp-KrYqf-multichunk-a6aaceef013c1697c4a12f04b8f17a2432cae06f], final location: RemoteFile[name=multichunk-a6aaceef013c1697c4a12f04b8f17a2432cae06f]
18-11-18 14:32:58.221 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=C/(A4,B1,C1)/T=1542551578221, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
18-11-18 14:32:58.222 | UpOperation     | Test worker    | INFO : Saving local delta database, version C/(A4,B1,C1)/T=1542551578221 to file /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/database-C-0000000001 ... 
18-11-18 14:32:58.222 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/database-C-0000000001 ...
18-11-18 14:32:58.222 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
18-11-18 14:32:58.222 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/database-C-0000000001 to RemoteFile[name=database-C-0000000001] ...
18-11-18 14:32:58.222 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/database-C-0000000001 -> Temp. remote file: RemoteFile[name=temp-lOSRj-database-C-0000000001], final location: RemoteFile[name=database-C-0000000001]
18-11-18 14:32:58.223 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
18-11-18 14:32:58.223 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
18-11-18 14:32:58.224 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/temp-transaction-3678054248435501214.tmp
18-11-18 14:32:58.224 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@6167cd59) ...
18-11-18 14:32:58.224 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-2c6c91e4] ...
18-11-18 14:32:58.224 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
18-11-18 14:32:58.224 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@646a9dad) ...
18-11-18 14:32:58.224 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/multichunk-a6aaceef013c1697c4a12f04b8f17a2432cae06f to temp. file RemoteFile[name=temp-KrYqf-multichunk-a6aaceef013c1697c4a12f04b8f17a2432cae06f] ...
18-11-18 14:32:58.225 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@ae5695) ...
18-11-18 14:32:58.225 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-181118143132272-55686-client-C/.syncany/cache/database-C-0000000001 to temp. file RemoteFile[name=temp-lOSRj-database-C-0000000001] ...
18-11-18 14:32:58.225 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-KrYqf-multichunk-a6aaceef013c1697c4a12f04b8f17a2432cae06f] to final location RemoteFile[name=multichunk-a6aaceef013c1697c4a12f04b8f17a2432cae06f] ...
18-11-18 14:32:58.225 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-lOSRj-database-C-0000000001] to final location RemoteFile[name=database-C-0000000001] ...
18-11-18 14:32:58.225 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-2c6c91e4] ...
18-11-18 14:32:58.225 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
18-11-18 14:32:58.225 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
18-11-18 14:32:58.225 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version C/(A4,B1,C1)/T=1542551578221) ...
18-11-18 14:32:58.227 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
18-11-18 14:32:58.227 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@79c368e) ...
18-11-18 14:32:58.231 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
18-11-18 14:32:58.235 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=C/(A4,B1,C1)/T=1542551578221, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
18-11-18 14:32:58.235 | UpOperation     | Test worker    | INFO : Committing local database.
18-11-18 14:32:58.235 | UpOperation     | Test worker    | FINE : Waiting for new database version.
18-11-18 14:32:58.235 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1542551578231, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
18-11-18 14:32:58.235 | UpOperation     | Test worker    | INFO : Sync up done.
18-11-18 14:32:58.237 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-C-1542551578195] ...
18-11-18 14:32:58.242 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-C-1542551578195]
18-11-18 14:32:58.242 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
18-11-18 14:32:58.242 | Cache           | Test worker    | INFO : Cache size okay (207 KB), no need to clean (keep size is 500 MB)
18-11-18 14:32:58.243 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@7d220d48) ...
18-11-18 14:32:58.243 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:58.243 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-A' ...
18-11-18 14:32:58.243 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:58.243 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:58.243 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:58.243 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:58.243 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:58.243 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:58.243 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:58.243 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:58.243 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:58.243 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-A' ...
18-11-18 14:32:58.243 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:58.243 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:58.243 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:32:58.243 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:32:58.243 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:58.243 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:58.243 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:58.243 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:58.243 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:58.243 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:58.243 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:32:58.243 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:32:58.246 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:58.246 | DownOperation   | Test worker    | INFO : 
18-11-18 14:32:58.246 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client A ...
18-11-18 14:32:58.246 | DownOperation   | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:58.246 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@7b3769e2) ...
18-11-18 14:32:58.246 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:32:58.247 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:58.247 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:32:58.247 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
18-11-18 14:32:58.247 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:58.247 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@6600057d) ...
18-11-18 14:32:58.247 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:32:58.247 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
18-11-18 14:32:58.247 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
18-11-18 14:32:58.247 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
18-11-18 14:32:58.247 | LsRemoteOperati | Test worker    | INFO : - Remote database database-C-0000000001 is new.
18-11-18 14:32:58.247 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
18-11-18 14:32:58.247 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
18-11-18 14:32:58.247 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@e8e67e7) ...
18-11-18 14:32:58.247 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@2d00ba5b) ...
18-11-18 14:32:58.247 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-A-1542551578243] ...
18-11-18 14:32:58.247 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-A-1542551578243]
18-11-18 14:32:58.248 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-A-1542551578243] ...
18-11-18 14:32:58.248 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
18-11-18 14:32:58.248 | DownOperation   | Test worker    | INFO : - Downloading database-C-0000000001 to local cache at /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-C-0000000001
18-11-18 14:32:58.248 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@4b376c60) ...
18-11-18 14:32:58.249 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
18-11-18 14:32:58.249 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-C-0000000001 ...
18-11-18 14:32:58.250 | DatabaseXmlPars | Test worker    | INFO :    + Added database version C/(A4,B1,C1)/T=1542551578221
18-11-18 14:32:58.250 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:58.250 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:58.250 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:58.250 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:58.250 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:58.251 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-C-0000000001; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:58.251 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
18-11-18 14:32:58.251 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1542551577481, A/(A2)/T=1542551577532, A/(A3)/T=1542551577589, A/(A4)/T=1542551577621, B/(A4,B1)/T=1542551577843], C=[C/(A4,B1,C1)/T=1542551578221]}
18-11-18 14:32:58.251 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
18-11-18 14:32:58.251 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1542551577481
18-11-18 14:32:58.251 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1542551577532
18-11-18 14:32:58.251 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3)/T=1542551577589
18-11-18 14:32:58.251 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A4)/T=1542551577621
18-11-18 14:32:58.251 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A4,B1)/T=1542551577843
18-11-18 14:32:58.251 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: C/(A4,B1,C1)/T=1542551578221
18-11-18 14:32:58.251 | DatabaseReconci | Test worker    | INFO : - Winner is C with branch: 
18-11-18 14:32:58.251 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1542551577481
18-11-18 14:32:58.251 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1542551577532
18-11-18 14:32:58.251 | DatabaseReconci | Test worker    | INFO :   + A/(A3)/T=1542551577589
18-11-18 14:32:58.251 | DatabaseReconci | Test worker    | INFO :   + A/(A4)/T=1542551577621
18-11-18 14:32:58.251 | DatabaseReconci | Test worker    | INFO :   + B/(A4,B1)/T=1542551577843
18-11-18 14:32:58.251 | DatabaseReconci | Test worker    | INFO :   + C/(A4,B1,C1)/T=1542551578221
18-11-18 14:32:58.251 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
18-11-18 14:32:58.251 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
18-11-18 14:32:58.251 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
18-11-18 14:32:58.251 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1542551577481, A/(A2)/T=1542551577532, A/(A3)/T=1542551577589, A/(A4)/T=1542551577621, B/(A4,B1)/T=1542551577843]
18-11-18 14:32:58.251 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1542551577481, A/(A2)/T=1542551577532, A/(A3)/T=1542551577589, A/(A4)/T=1542551577621, B/(A4,B1)/T=1542551577843, C/(A4,B1,C1)/T=1542551578221]
18-11-18 14:32:58.251 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
18-11-18 14:32:58.251 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [C/(A4,B1,C1)/T=1542551578221]
18-11-18 14:32:58.251 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
18-11-18 14:32:58.251 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/database-C-0000000001 ...
18-11-18 14:32:58.252 | DatabaseXmlPars | Test worker    | INFO :    + Added database version C/(A4,B1,C1)/T=1542551578221
18-11-18 14:32:58.253 | DownOperation   | Test worker    | INFO : Determine file system actions ...
18-11-18 14:32:58.254 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:58.257 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
18-11-18 14:32:58.257 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
18-11-18 14:32:58.257 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
18-11-18 14:32:58.257 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=52cb4c852352454589923a722ccbc565cdaa574a, updated=Sun Nov 18 14:32:58 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:32:58.257 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file C1
18-11-18 14:32:58.257 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=52cb4c852352454589923a722ccbc565cdaa574a, updated=Sun Nov 18 14:32:58 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-181118143132272-55686-client-A/C1
18-11-18 14:32:58.257 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=52cb4c852352454589923a722ccbc565cdaa574a, updated=Sun Nov 18 14:32:58 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
18-11-18 14:32:58.258 | DownOperation   | Test worker    | INFO :   + Adding multichunk a6aaceef013c1697c4a12f04b8f17a2432cae06f to download list ...
18-11-18 14:32:58.258 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
18-11-18 14:32:58.259 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@69f1bcc3) ...
18-11-18 14:32:58.259 | Downloader      | Test worker    | INFO :   + Downloading multichunk a6aaceef013c1697c4a12f04b8f17a2432cae06f ...
18-11-18 14:32:58.259 | Downloader      | Test worker    | INFO :   + Decrypting multichunk a6aaceef013c1697c4a12f04b8f17a2432cae06f ...
18-11-18 14:32:58.261 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk a6aaceef013c1697c4a12f04b8f17a2432cae06f ...
18-11-18 14:32:58.261 | FileSystemActio | Test worker    | INFO :    Sorted actions:
18-11-18 14:32:58.261 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=52cb4c852352454589923a722ccbc565cdaa574a, updated=Sun Nov 18 14:32:58 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
18-11-18 14:32:58.261 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
18-11-18 14:32:58.261 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=52cb4c852352454589923a722ccbc565cdaa574a, updated=Sun Nov 18 14:32:58 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
18-11-18 14:32:58.261 | Assembler       | Test worker    | INFO :      - Creating file C1 to /tmp/syncanytest/syncany-181118143132272-55686-client-A/.syncany/cache/temp-reconstructedFileVersion-3544731645736795411.tmp ...
18-11-18 14:32:58.262 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
18-11-18 14:32:58.263 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
18-11-18 14:32:58.263 | DownOperation   | Test worker    | INFO :   + Applying database version (A4,B1,C1)
18-11-18 14:32:58.263 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=C/(A4,B1,C1)/T=1542551578221, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
18-11-18 14:32:58.272 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-A-1542551578243] ...
18-11-18 14:32:58.278 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-A-1542551578243]
18-11-18 14:32:58.278 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
18-11-18 14:32:58.278 | Cache           | Test worker    | INFO : Cache size okay (257 KB), no need to clean (keep size is 500 MB)
18-11-18 14:32:58.278 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@122e740f) ...
18-11-18 14:32:58.279 | DownOperation   | Test worker    | INFO : Sync down done.
18-11-18 14:32:58.279 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:58.279 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-B' ...
18-11-18 14:32:58.279 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:58.279 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:58.279 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:58.279 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:58.279 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:58.279 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:58.279 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:58.279 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:58.279 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:58.279 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-B' ...
18-11-18 14:32:58.279 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:58.279 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:58.279 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:32:58.279 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:32:58.279 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:58.279 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:58.279 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:58.279 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:58.279 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:58.279 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:58.279 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:32:58.279 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:32:58.286 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:58.286 | DownOperation   | Test worker    | INFO : 
18-11-18 14:32:58.286 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
18-11-18 14:32:58.286 | DownOperation   | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:58.286 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@30e950da) ...
18-11-18 14:32:58.286 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:32:58.287 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:58.287 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:32:58.287 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
18-11-18 14:32:58.287 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:58.287 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@3c0c03bb) ...
18-11-18 14:32:58.287 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:32:58.287 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
18-11-18 14:32:58.287 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
18-11-18 14:32:58.287 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
18-11-18 14:32:58.287 | LsRemoteOperati | Test worker    | INFO : - Remote database database-C-0000000001 is new.
18-11-18 14:32:58.287 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
18-11-18 14:32:58.287 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
18-11-18 14:32:58.287 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@7c17222) ...
18-11-18 14:32:58.287 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@46337b74) ...
18-11-18 14:32:58.287 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1542551578279] ...
18-11-18 14:32:58.287 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1542551578279]
18-11-18 14:32:58.287 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1542551578279] ...
18-11-18 14:32:58.288 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
18-11-18 14:32:58.288 | DownOperation   | Test worker    | INFO : - Downloading database-C-0000000001 to local cache at /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/database-C-0000000001
18-11-18 14:32:58.288 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@4f39c0f1) ...
18-11-18 14:32:58.288 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
18-11-18 14:32:58.288 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/database-C-0000000001 ...
18-11-18 14:32:58.290 | DatabaseXmlPars | Test worker    | INFO :    + Added database version C/(A4,B1,C1)/T=1542551578221
18-11-18 14:32:58.290 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:58.290 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:58.290 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:58.290 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:58.290 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:58.290 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-181118143132272-55686-repo/databases/database-C-0000000001; maybe invalid file name pattern. Ignoring file.
18-11-18 14:32:58.290 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
18-11-18 14:32:58.290 | DownOperation   | Test worker    | INFO : Populated unknown branches: {B=[A/(A1)/T=1542551577481, A/(A2)/T=1542551577532, A/(A3)/T=1542551577589, A/(A4)/T=1542551577621, B/(A4,B1)/T=1542551577843], C=[C/(A4,B1,C1)/T=1542551578221]}
18-11-18 14:32:58.290 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
18-11-18 14:32:58.290 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1542551577481
18-11-18 14:32:58.290 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1542551577532
18-11-18 14:32:58.290 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3)/T=1542551577589
18-11-18 14:32:58.290 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A4)/T=1542551577621
18-11-18 14:32:58.290 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A4,B1)/T=1542551577843
18-11-18 14:32:58.290 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: C/(A4,B1,C1)/T=1542551578221
18-11-18 14:32:58.291 | DatabaseReconci | Test worker    | INFO : - Winner is C with branch: 
18-11-18 14:32:58.291 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1542551577481
18-11-18 14:32:58.291 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1542551577532
18-11-18 14:32:58.291 | DatabaseReconci | Test worker    | INFO :   + A/(A3)/T=1542551577589
18-11-18 14:32:58.291 | DatabaseReconci | Test worker    | INFO :   + A/(A4)/T=1542551577621
18-11-18 14:32:58.291 | DatabaseReconci | Test worker    | INFO :   + B/(A4,B1)/T=1542551577843
18-11-18 14:32:58.291 | DatabaseReconci | Test worker    | INFO :   + C/(A4,B1,C1)/T=1542551578221
18-11-18 14:32:58.291 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
18-11-18 14:32:58.291 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
18-11-18 14:32:58.291 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
18-11-18 14:32:58.291 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1542551577481, A/(A2)/T=1542551577532, A/(A3)/T=1542551577589, A/(A4)/T=1542551577621, B/(A4,B1)/T=1542551577843]
18-11-18 14:32:58.291 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1542551577481, A/(A2)/T=1542551577532, A/(A3)/T=1542551577589, A/(A4)/T=1542551577621, B/(A4,B1)/T=1542551577843, C/(A4,B1,C1)/T=1542551578221]
18-11-18 14:32:58.291 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
18-11-18 14:32:58.291 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [C/(A4,B1,C1)/T=1542551578221]
18-11-18 14:32:58.291 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
18-11-18 14:32:58.291 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/database-C-0000000001 ...
18-11-18 14:32:58.292 | DatabaseXmlPars | Test worker    | INFO :    + Added database version C/(A4,B1,C1)/T=1542551578221
18-11-18 14:32:58.298 | DownOperation   | Test worker    | INFO : Determine file system actions ...
18-11-18 14:32:58.299 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:58.300 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
18-11-18 14:32:58.300 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
18-11-18 14:32:58.300 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
18-11-18 14:32:58.300 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=52cb4c852352454589923a722ccbc565cdaa574a, updated=Sun Nov 18 14:32:58 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]
18-11-18 14:32:58.307 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file C1
18-11-18 14:32:58.307 | FileSystemActio | Test worker    | INFO :      -> (2) Deleted: Local file does NOT exist, but it should, winning version not known: FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=52cb4c852352454589923a722ccbc565cdaa574a, updated=Sun Nov 18 14:32:58 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-181118143132272-55686-client-B/C1
18-11-18 14:32:58.307 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=52cb4c852352454589923a722ccbc565cdaa574a, updated=Sun Nov 18 14:32:58 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
18-11-18 14:32:58.308 | DownOperation   | Test worker    | INFO :   + Adding multichunk a6aaceef013c1697c4a12f04b8f17a2432cae06f to download list ...
18-11-18 14:32:58.308 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
18-11-18 14:32:58.308 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@7e34b497) ...
18-11-18 14:32:58.308 | Downloader      | Test worker    | INFO :   + Downloading multichunk a6aaceef013c1697c4a12f04b8f17a2432cae06f ...
18-11-18 14:32:58.309 | Downloader      | Test worker    | INFO :   + Decrypting multichunk a6aaceef013c1697c4a12f04b8f17a2432cae06f ...
18-11-18 14:32:58.309 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk a6aaceef013c1697c4a12f04b8f17a2432cae06f ...
18-11-18 14:32:58.310 | FileSystemActio | Test worker    | INFO :    Sorted actions:
18-11-18 14:32:58.310 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=52cb4c852352454589923a722ccbc565cdaa574a, updated=Sun Nov 18 14:32:58 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
18-11-18 14:32:58.310 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
18-11-18 14:32:58.311 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Sun Nov 18 14:32:57 UTC 2018, linkTarget=null, checksum=52cb4c852352454589923a722ccbc565cdaa574a, updated=Sun Nov 18 14:32:58 UTC 2018, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
18-11-18 14:32:58.311 | Assembler       | Test worker    | INFO :      - Creating file C1 to /tmp/syncanytest/syncany-181118143132272-55686-client-B/.syncany/cache/temp-reconstructedFileVersion-4841523028141954158.tmp ...
18-11-18 14:32:58.312 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
18-11-18 14:32:58.312 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
18-11-18 14:32:58.312 | DownOperation   | Test worker    | INFO :   + Applying database version (A4,B1,C1)
18-11-18 14:32:58.312 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=C/(A4,B1,C1)/T=1542551578221, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
18-11-18 14:32:58.323 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1542551578279] ...
18-11-18 14:32:58.326 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1542551578279]
18-11-18 14:32:58.327 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
18-11-18 14:32:58.327 | Cache           | Test worker    | INFO : Cache size okay (207 KB), no need to clean (keep size is 500 MB)
18-11-18 14:32:58.327 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@79eef655) ...
18-11-18 14:32:58.327 | DownOperation   | Test worker    | INFO : Sync down done.
18-11-18 14:32:58.327 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:58.327 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-C' ...
18-11-18 14:32:58.327 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:58.327 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:58.327 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:58.327 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:58.327 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:58.327 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:58.327 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:58.327 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:58.327 | org.syncany.plu | Test worker    | FINE : Validating required fields
18-11-18 14:32:58.327 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-181118143132272-55686-client-C' ...
18-11-18 14:32:58.327 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
18-11-18 14:32:58.327 | TransferManager | Test worker    | INFO : - With feature Retriable
18-11-18 14:32:58.327 | TransferManager | Test worker    | INFO : - With feature PathAware
18-11-18 14:32:58.327 | TransferManager | Test worker    | INFO : - With feature TransactionAware
18-11-18 14:32:58.328 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
18-11-18 14:32:58.328 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
18-11-18 14:32:58.328 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
18-11-18 14:32:58.328 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
18-11-18 14:32:58.328 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
18-11-18 14:32:58.328 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
18-11-18 14:32:58.328 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
18-11-18 14:32:58.328 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
18-11-18 14:32:58.333 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:58.333 | DownOperation   | Test worker    | INFO : 
18-11-18 14:32:58.333 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client C ...
18-11-18 14:32:58.333 | DownOperation   | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:58.333 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@1c81572a) ...
18-11-18 14:32:58.333 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
18-11-18 14:32:58.334 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
18-11-18 14:32:58.334 | LsRemoteOperati | Test worker    | INFO : 
18-11-18 14:32:58.334 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
18-11-18 14:32:58.334 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
18-11-18 14:32:58.334 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@53fbf37b) ...
18-11-18 14:32:58.334 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
18-11-18 14:32:58.334 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
18-11-18 14:32:58.334 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
18-11-18 14:32:58.334 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
18-11-18 14:32:58.334 | LsRemoteOperati | Test worker    | INFO : - Remote database database-C-0000000001 is already known (in local database). Ignoring.
18-11-18 14:32:58.334 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
18-11-18 14:32:58.334 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
18-11-18 14:32:58.334 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@20b85089) ...
18-11-18 14:32:58.334 | DownOperation   | Test worker    | INFO : * Nothing new. Skipping down operation.
18-11-18 14:32:58.334 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@32d5f989) ...
18-11-18 14:32:58.339 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-181118143132272-55686-client-A/A2, but actual PATH = tmp/syncanytest/syncany-181118143132272-55686-client-B/A2, for file tmp/syncanytest/syncany-181118143132272-55686-client-B/A2
18-11-18 14:32:58.341 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-181118143132272-55686-client-A/A4,B1, but actual PATH = tmp/syncanytest/syncany-181118143132272-55686-client-B/A4,B1, for file tmp/syncanytest/syncany-181118143132272-55686-client-B/A4,B1
18-11-18 14:32:58.343 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-181118143132272-55686-client-A/C1, but actual PATH = tmp/syncanytest/syncany-181118143132272-55686-client-B/C1, for file tmp/syncanytest/syncany-181118143132272-55686-client-B/C1
18-11-18 14:32:58.355 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-181118143132272-55686-client-B/A2, but actual PATH = tmp/syncanytest/syncany-181118143132272-55686-client-C/A2, for file tmp/syncanytest/syncany-181118143132272-55686-client-C/A2
18-11-18 14:32:58.359 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-181118143132272-55686-client-B/A4,B1, but actual PATH = tmp/syncanytest/syncany-181118143132272-55686-client-C/A4,B1, for file tmp/syncanytest/syncany-181118143132272-55686-client-C/A4,B1
18-11-18 14:32:58.368 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-181118143132272-55686-client-B/C1, but actual PATH = tmp/syncanytest/syncany-181118143132272-55686-client-C/C1, for file tmp/syncanytest/syncany-181118143132272-55686-client-C/C1