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

1

tests

0

failures

0

ignored

1.144s

duration

100%

successful

Tests

Test Duration Result
testEvilC 1.144s passed

Standard error

27-4-17 11:01:32.532 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:32.533 | LocalTransferMa | Test worker    | INFO : testTargetExists: Target exists.
27-4-17 11:01:32.543 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:32.543 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-A' ...
27-4-17 11:01:32.543 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:32.543 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:32.543 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:32.543 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:32.544 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:32.544 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:32.544 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:32.544 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:32.544 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:32.544 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-A' ...
27-4-17 11:01:32.544 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:32.544 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:32.544 | TransferManager | Test worker    | INFO : - With feature PathAware
27-4-17 11:01:32.544 | TransferManager | Test worker    | INFO : - With feature TransactionAware
27-4-17 11:01:32.544 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:32.544 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:32.544 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:32.544 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:32.545 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:32.545 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:32.545 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
27-4-17 11:01:32.546 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
27-4-17 11:01:32.565 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
27-4-17 11:01:32.565 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
27-4-17 11:01:32.575 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
27-4-17 11:01:32.578 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
27-4-17 11:01:32.579 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
27-4-17 11:01:32.584 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
27-4-17 11:01:32.585 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
27-4-17 11:01:32.585 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
27-4-17 11:01:32.585 | 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) ); 
27-4-17 11:01:32.589 | 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 ); 
27-4-17 11:01:32.591 | 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 ); 
27-4-17 11:01:32.596 | 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 ); 
27-4-17 11:01:32.599 | 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 ); 
27-4-17 11:01:32.602 | 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 ); 
27-4-17 11:01:32.604 | 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 ); 
27-4-17 11:01:32.607 | 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 ); 
27-4-17 11:01:32.609 | 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 ); 
27-4-17 11:01:32.612 | 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) ); 
27-4-17 11:01:32.614 | 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) ); 
27-4-17 11:01:32.616 | 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) ); 
27-4-17 11:01:32.619 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
27-4-17 11:01:32.619 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
27-4-17 11:01:32.620 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
27-4-17 11:01:32.623 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
27-4-17 11:01:32.625 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
27-4-17 11:01:32.627 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
27-4-17 11:01:32.630 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
27-4-17 11:01:32.632 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
27-4-17 11:01:32.634 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
27-4-17 11:01:32.634 | 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'; 
27-4-17 11:01:32.637 | 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'; 
27-4-17 11:01:32.640 | 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; 
27-4-17 11:01:32.643 | 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'; 
27-4-17 11:01:32.646 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
27-4-17 11:01:32.646 | 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; 
27-4-17 11:01:32.648 | 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; 
27-4-17 11:01:32.669 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
27-4-17 11:01:32.670 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
27-4-17 11:01:32.670 | 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; 
27-4-17 11:01:32.674 | UpOperation     | Test worker    | INFO : 
27-4-17 11:01:32.674 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
27-4-17 11:01:32.674 | UpOperation     | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:32.674 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@57fb4a33) ...
27-4-17 11:01:32.674 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:32.674 | StatusOperation | Test worker    | INFO : 
27-4-17 11:01:32.674 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
27-4-17 11:01:32.674 | StatusOperation | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:32.674 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
27-4-17 11:01:32.674 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
27-4-17 11:01:32.675 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@4ff37e07) ...
27-4-17 11:01:32.675 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-170427110008054-46179-client-A ...
27-4-17 11:01:32.675 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
27-4-17 11:01:32.675 | StatusOperation | Test worker    | FINE : - New file: A1
27-4-17 11:01:32.675 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@7a02aa86) ...
27-4-17 11:01:32.675 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
27-4-17 11:01:32.676 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:32.676 | LsRemoteOperati | Test worker    | INFO : 
27-4-17 11:01:32.676 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
27-4-17 11:01:32.676 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:32.676 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@76bd7705) ...
27-4-17 11:01:32.676 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
27-4-17 11:01:32.676 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@1ad217cc) ...
27-4-17 11:01:32.676 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
27-4-17 11:01:32.676 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1493290892546] ...
27-4-17 11:01:32.676 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1493290892546]
27-4-17 11:01:32.677 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1493290892546] ...
27-4-17 11:01:32.677 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:32.685 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
27-4-17 11:01:32.686 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
27-4-17 11:01:32.686 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@106bb948) ...
27-4-17 11:01:32.686 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
27-4-17 11:01:32.686 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-170427110008054-46179-client-A/A1
27-4-17 11:01:32.686 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-170427110008054-46179-client-A/A1
27-4-17 11:01:32.689 | Indexer         | AsyncI/syncany | FINE : - Chunk new: 3bbf054717fb37875d5d76e6a673cd437309f4c5
27-4-17 11:01:32.689 | Indexer         | AsyncI/syncany | FINE : - +MultiChunk e1b2690c68c2d81aa47e77333962e29221485583
27-4-17 11:01:32.689 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: 3bbf054717fb37875d5d76e6a673cd437309f4c5 > e1b2690c68c2d81aa47e77333962e29221485583
27-4-17 11:01:32.689 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 3bbf054717fb37875d5d76e6a673cd437309f4c5 > /tmp/syncanytest/syncany-170427110008054-46179-client-A/A1
27-4-17 11:01:32.690 | Indexer         | AsyncI/syncany | FINE : - /File: A1 (checksum 3bbf054717fb37875d5d76e6a673cd437309f4c5)
27-4-17 11:01:32.690 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: A1, checksum: 3bbf054717fb37875d5d76e6a673cd437309f4c5)
27-4-17 11:01:32.690 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file A1
27-4-17 11:01:32.690 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=A1, type=FILE, status=NEW, size=51200, lastModified=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=3bbf054717fb37875d5d76e6a673cd437309f4c5, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
27-4-17 11:01:32.690 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
27-4-17 11:01:32.690 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@2e7c4559) ...
27-4-17 11:01:32.691 | Indexer         | AsyncI/syncany | FINE : - /MultiChunk e1b2690c68c2d81aa47e77333962e29221485583
27-4-17 11:01:32.691 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@54a63f8b) ...
27-4-17 11:01:32.691 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1493290892686, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
27-4-17 11:01:32.691 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
27-4-17 11:01:32.691 | UpOperation     | Test worker    | INFO : Last vector clock was: ()
27-4-17 11:01:32.691 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
27-4-17 11:01:32.692 | UpOperation     | Test worker    | INFO : - Uploading multichunk e1b2690c68c2d81aa47e77333962e29221485583 from /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/multichunk-e1b2690c68c2d81aa47e77333962e29221485583 to RemoteFile[name=multichunk-e1b2690c68c2d81aa47e77333962e29221485583] ...
27-4-17 11:01:32.692 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/multichunk-e1b2690c68c2d81aa47e77333962e29221485583 -> Temp. remote file: RemoteFile[name=temp-ohyoC-multichunk-e1b2690c68c2d81aa47e77333962e29221485583], final location: RemoteFile[name=multichunk-e1b2690c68c2d81aa47e77333962e29221485583]
27-4-17 11:01:32.692 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A1)/T=1493290892691, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
27-4-17 11:01:32.692 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A1)/T=1493290892691 to file /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-A-0000000001 ... 
27-4-17 11:01:32.692 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-A-0000000001 ...
27-4-17 11:01:32.693 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
27-4-17 11:01:32.693 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-A-0000000001 to RemoteFile[name=database-A-0000000001] ...
27-4-17 11:01:32.693 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-A-0000000001 -> Temp. remote file: RemoteFile[name=temp-GRFed-database-A-0000000001], final location: RemoteFile[name=database-A-0000000001]
27-4-17 11:01:32.693 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
27-4-17 11:01:32.693 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
27-4-17 11:01:32.694 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/temp-transaction-3097011362959155797.tmp
27-4-17 11:01:32.694 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@6a4e3271) ...
27-4-17 11:01:32.694 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-89a42eb] ...
27-4-17 11:01:32.695 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
27-4-17 11:01:32.695 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@619980d8) ...
27-4-17 11:01:32.695 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/multichunk-e1b2690c68c2d81aa47e77333962e29221485583 to temp. file RemoteFile[name=temp-ohyoC-multichunk-e1b2690c68c2d81aa47e77333962e29221485583] ...
27-4-17 11:01:32.695 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@1e1d928b) ...
27-4-17 11:01:32.695 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-A-0000000001 to temp. file RemoteFile[name=temp-GRFed-database-A-0000000001] ...
27-4-17 11:01:32.695 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-ohyoC-multichunk-e1b2690c68c2d81aa47e77333962e29221485583] to final location RemoteFile[name=multichunk-e1b2690c68c2d81aa47e77333962e29221485583] ...
27-4-17 11:01:32.695 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-GRFed-database-A-0000000001] to final location RemoteFile[name=database-A-0000000001] ...
27-4-17 11:01:32.696 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-89a42eb] ...
27-4-17 11:01:32.696 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
27-4-17 11:01:32.696 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
27-4-17 11:01:32.696 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A1)/T=1493290892691) ...
27-4-17 11:01:32.697 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@776de2bb) ...
27-4-17 11:01:32.706 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
27-4-17 11:01:32.711 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A1)/T=1493290892691, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
27-4-17 11:01:32.711 | UpOperation     | Test worker    | INFO : Committing local database.
27-4-17 11:01:32.711 | UpOperation     | Test worker    | FINE : Waiting for new database version.
27-4-17 11:01:32.714 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
27-4-17 11:01:32.714 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1493290892714, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
27-4-17 11:01:32.714 | UpOperation     | Test worker    | INFO : Sync up done.
27-4-17 11:01:32.716 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1493290892546] ...
27-4-17 11:01:32.721 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1493290892546]
27-4-17 11:01:32.721 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
27-4-17 11:01:32.722 | Cache           | Test worker    | INFO : Cache size okay (51 KB), no need to clean (keep size is 500 MB)
27-4-17 11:01:32.722 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@22a22665) ...
27-4-17 11:01:32.722 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:32.722 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-A' ...
27-4-17 11:01:32.722 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:32.722 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:32.722 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:32.722 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:32.722 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:32.722 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:32.722 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:32.722 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:32.722 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:32.722 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-A' ...
27-4-17 11:01:32.722 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:32.722 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:32.722 | TransferManager | Test worker    | INFO : - With feature PathAware
27-4-17 11:01:32.722 | TransferManager | Test worker    | INFO : - With feature TransactionAware
27-4-17 11:01:32.723 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:32.723 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:32.723 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:32.723 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:32.723 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:32.723 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:32.723 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
27-4-17 11:01:32.723 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
27-4-17 11:01:32.724 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:32.724 | UpOperation     | Test worker    | INFO : 
27-4-17 11:01:32.724 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
27-4-17 11:01:32.724 | UpOperation     | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:32.724 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@38481469) ...
27-4-17 11:01:32.724 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:32.724 | StatusOperation | Test worker    | INFO : 
27-4-17 11:01:32.724 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
27-4-17 11:01:32.724 | StatusOperation | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:32.724 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
27-4-17 11:01:32.724 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
27-4-17 11:01:32.725 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@43f5b90) ...
27-4-17 11:01:32.725 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-170427110008054-46179-client-A ...
27-4-17 11:01:32.725 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
27-4-17 11:01:32.725 | StatusOperation | Test worker    | FINE : - New file: A2
27-4-17 11:01:32.726 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@70d4bcaa) ...
27-4-17 11:01:32.726 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
27-4-17 11:01:32.726 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:32.726 | LsRemoteOperati | Test worker    | INFO : 
27-4-17 11:01:32.726 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
27-4-17 11:01:32.726 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:32.726 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@5d1db3f6) ...
27-4-17 11:01:32.726 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
27-4-17 11:01:32.726 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
27-4-17 11:01:32.726 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@388d72d8) ...
27-4-17 11:01:32.726 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
27-4-17 11:01:32.726 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1493290892723] ...
27-4-17 11:01:32.726 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1493290892723]
27-4-17 11:01:32.727 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1493290892723] ...
27-4-17 11:01:32.727 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:32.730 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
27-4-17 11:01:32.731 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
27-4-17 11:01:32.731 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@54102166) ...
27-4-17 11:01:32.731 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
27-4-17 11:01:32.734 | Indexer         | AsyncI/syncany | FINE :   + Deleted: Adding DELETED version: FileVersion [version=2, path=A1, type=FILE, status=DELETED, size=51200, lastModified=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=3bbf054717fb37875d5d76e6a673cd437309f4c5, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
27-4-17 11:01:32.734 | Indexer         | AsyncI/syncany | FINE :                            based on: FileVersion [version=1, path=A1, type=FILE, status=NEW, size=51200, lastModified=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=3bbf054717fb37875d5d76e6a673cd437309f4c5, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
27-4-17 11:01:32.735 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-170427110008054-46179-client-A/A2
27-4-17 11:01:32.735 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-170427110008054-46179-client-A/A2
27-4-17 11:01:32.736 | Indexer         | AsyncI/syncany | FINE : - Chunk exists: 3bbf054717fb37875d5d76e6a673cd437309f4c5
27-4-17 11:01:32.738 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 3bbf054717fb37875d5d76e6a673cd437309f4c5 > /tmp/syncanytest/syncany-170427110008054-46179-client-A/A2
27-4-17 11:01:32.738 | Indexer         | AsyncI/syncany | FINE : - /File: A2 (checksum 3bbf054717fb37875d5d76e6a673cd437309f4c5)
27-4-17 11:01:32.740 | Indexer         | AsyncI/syncany | FINE :    * Found old file history e1ad43866bfad0de3a723669c0b5b44d757e3067 (by checksum: 3bbf054717fb37875d5d76e6a673cd437309f4c5), appending new version.
27-4-17 11:01:32.741 | FileVersionComp | AsyncI/syncany | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = A2, but actual PATH = A1, for file A1
27-4-17 11:01:32.742 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=2, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=3bbf054717fb37875d5d76e6a673cd437309f4c5, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
27-4-17 11:01:32.742 | Indexer         | AsyncI/syncany | INFO :      based on file version: FileVersion [version=1, path=A1, type=FILE, status=NEW, size=51200, lastModified=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=3bbf054717fb37875d5d76e6a673cd437309f4c5, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
27-4-17 11:01:32.742 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@2a87c0ea) ...
27-4-17 11:01:32.743 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@14b232aa) ...
27-4-17 11:01:32.743 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1493290892731, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
27-4-17 11:01:32.743 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
27-4-17 11:01:32.744 | UpOperation     | Test worker    | INFO : Last vector clock was: (A1)
27-4-17 11:01:32.744 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
27-4-17 11:01:32.744 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A2)/T=1493290892744, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
27-4-17 11:01:32.744 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A2)/T=1493290892744 to file /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-A-0000000002 ... 
27-4-17 11:01:32.744 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-A-0000000002 ...
27-4-17 11:01:32.745 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
27-4-17 11:01:32.745 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-A-0000000002 to RemoteFile[name=database-A-0000000002] ...
27-4-17 11:01:32.745 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-A-0000000002 -> Temp. remote file: RemoteFile[name=temp-peECe-database-A-0000000002], final location: RemoteFile[name=database-A-0000000002]
27-4-17 11:01:32.745 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
27-4-17 11:01:32.745 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
27-4-17 11:01:32.750 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/temp-transaction-4841453045062774416.tmp
27-4-17 11:01:32.750 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@255832c3) ...
27-4-17 11:01:32.750 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-20aeb25c] ...
27-4-17 11:01:32.754 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
27-4-17 11:01:32.754 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@286cc6f6) ...
27-4-17 11:01:32.754 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-A-0000000002 to temp. file RemoteFile[name=temp-peECe-database-A-0000000002] ...
27-4-17 11:01:32.754 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-peECe-database-A-0000000002] to final location RemoteFile[name=database-A-0000000002] ...
27-4-17 11:01:32.754 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-20aeb25c] ...
27-4-17 11:01:32.755 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
27-4-17 11:01:32.755 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
27-4-17 11:01:32.755 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A2)/T=1493290892744) ...
27-4-17 11:01:32.756 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
27-4-17 11:01:32.757 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@7b953808) ...
27-4-17 11:01:32.763 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
27-4-17 11:01:32.767 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A2)/T=1493290892744, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
27-4-17 11:01:32.767 | UpOperation     | Test worker    | INFO : Committing local database.
27-4-17 11:01:32.767 | UpOperation     | Test worker    | FINE : Waiting for new database version.
27-4-17 11:01:32.767 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1493290892763, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
27-4-17 11:01:32.767 | UpOperation     | Test worker    | INFO : Sync up done.
27-4-17 11:01:32.769 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1493290892723] ...
27-4-17 11:01:32.778 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1493290892723]
27-4-17 11:01:32.778 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
27-4-17 11:01:32.778 | Cache           | Test worker    | INFO : Cache size okay (52 KB), no need to clean (keep size is 500 MB)
27-4-17 11:01:32.778 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@5dcf2182) ...
27-4-17 11:01:32.779 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:32.779 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-A' ...
27-4-17 11:01:32.779 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:32.779 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:32.779 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:32.779 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:32.779 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:32.779 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:32.779 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:32.779 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:32.779 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:32.779 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-A' ...
27-4-17 11:01:32.779 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:32.779 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:32.779 | TransferManager | Test worker    | INFO : - With feature PathAware
27-4-17 11:01:32.779 | TransferManager | Test worker    | INFO : - With feature TransactionAware
27-4-17 11:01:32.779 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:32.779 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:32.779 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:32.779 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:32.779 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:32.779 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:32.779 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
27-4-17 11:01:32.779 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
27-4-17 11:01:32.786 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:32.786 | UpOperation     | Test worker    | INFO : 
27-4-17 11:01:32.786 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
27-4-17 11:01:32.786 | UpOperation     | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:32.786 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@213919ae) ...
27-4-17 11:01:32.787 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:32.787 | StatusOperation | Test worker    | INFO : 
27-4-17 11:01:32.787 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
27-4-17 11:01:32.787 | StatusOperation | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:32.787 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
27-4-17 11:01:32.787 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
27-4-17 11:01:32.787 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@798dd18f) ...
27-4-17 11:01:32.787 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-170427110008054-46179-client-A ...
27-4-17 11:01:32.788 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
27-4-17 11:01:32.788 | FileVersionComp | Test worker    | INFO :      - [CHANGED_CHECKSUM]: Local file DIFFERS from file version, expected CHECKSUM = 3bbf054717fb37875d5d76e6a673cd437309f4c5, but actual CHECKSUM = 6be7cf28a705f4ef3be486457ae0624fca1c4c20, for file A2
27-4-17 11:01:32.788 | StatusOperation | Test worker    | FINE : - New file: A3
27-4-17 11:01:32.788 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@45abcaf4) ...
27-4-17 11:01:32.788 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
27-4-17 11:01:32.789 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:32.789 | LsRemoteOperati | Test worker    | INFO : 
27-4-17 11:01:32.789 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
27-4-17 11:01:32.789 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:32.789 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@4437720d) ...
27-4-17 11:01:32.789 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
27-4-17 11:01:32.789 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
27-4-17 11:01:32.789 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
27-4-17 11:01:32.789 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@5100f06d) ...
27-4-17 11:01:32.789 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
27-4-17 11:01:32.789 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1493290892779] ...
27-4-17 11:01:32.789 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1493290892779]
27-4-17 11:01:32.790 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1493290892779] ...
27-4-17 11:01:32.790 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:32.793 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
27-4-17 11:01:32.793 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
27-4-17 11:01:32.794 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@4557c52a) ...
27-4-17 11:01:32.794 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
27-4-17 11:01:32.794 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-170427110008054-46179-client-A/A3
27-4-17 11:01:32.794 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-170427110008054-46179-client-A/A3
27-4-17 11:01:32.797 | Indexer         | AsyncI/syncany | FINE : - Chunk new: db017b97ff6e9e8df6c8ba9158064dd65824bc95
27-4-17 11:01:32.797 | Indexer         | AsyncI/syncany | FINE : - +MultiChunk ae3a61fcfff78f7ead9c9522a6cae28e5e390983
27-4-17 11:01:32.798 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: db017b97ff6e9e8df6c8ba9158064dd65824bc95 > ae3a61fcfff78f7ead9c9522a6cae28e5e390983
27-4-17 11:01:32.800 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: db017b97ff6e9e8df6c8ba9158064dd65824bc95 > /tmp/syncanytest/syncany-170427110008054-46179-client-A/A3
27-4-17 11:01:32.800 | Indexer         | AsyncI/syncany | FINE : - /File: A3 (checksum db017b97ff6e9e8df6c8ba9158064dd65824bc95)
27-4-17 11:01:32.801 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: A3, checksum: db017b97ff6e9e8df6c8ba9158064dd65824bc95)
27-4-17 11:01:32.802 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file A3
27-4-17 11:01:32.802 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=A3, type=FILE, status=NEW, size=51200, lastModified=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=db017b97ff6e9e8df6c8ba9158064dd65824bc95, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
27-4-17 11:01:32.802 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
27-4-17 11:01:32.802 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@12069a9d) ...
27-4-17 11:01:32.803 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-170427110008054-46179-client-A/A2
27-4-17 11:01:32.803 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-170427110008054-46179-client-A/A2
27-4-17 11:01:32.804 | Indexer         | AsyncI/syncany | FINE : - Chunk new: 6be7cf28a705f4ef3be486457ae0624fca1c4c20
27-4-17 11:01:32.812 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: 6be7cf28a705f4ef3be486457ae0624fca1c4c20 > ae3a61fcfff78f7ead9c9522a6cae28e5e390983
27-4-17 11:01:32.813 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 6be7cf28a705f4ef3be486457ae0624fca1c4c20 > /tmp/syncanytest/syncany-170427110008054-46179-client-A/A2
27-4-17 11:01:32.813 | Indexer         | AsyncI/syncany | FINE : - /File: A2 (checksum 6be7cf28a705f4ef3be486457ae0624fca1c4c20)
27-4-17 11:01:32.815 | Indexer         | AsyncI/syncany | FINE :    * Found old file history e1ad43866bfad0de3a723669c0b5b44d757e3067 (by path: A2), appending new version.
27-4-17 11:01:32.816 | FileVersionComp | AsyncI/syncany | INFO :      - [CHANGED_CHECKSUM]: Local file DIFFERS from file version, expected CHECKSUM = 6be7cf28a705f4ef3be486457ae0624fca1c4c20, but actual CHECKSUM = 3bbf054717fb37875d5d76e6a673cd437309f4c5, for file A2
27-4-17 11:01:32.816 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=6be7cf28a705f4ef3be486457ae0624fca1c4c20, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
27-4-17 11:01:32.816 | Indexer         | AsyncI/syncany | INFO :      based on file version: FileVersion [version=2, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=3bbf054717fb37875d5d76e6a673cd437309f4c5, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
27-4-17 11:01:32.817 | Indexer         | AsyncI/syncany | FINE : - /MultiChunk ae3a61fcfff78f7ead9c9522a6cae28e5e390983
27-4-17 11:01:32.818 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@5cecd89c) ...
27-4-17 11:01:32.818 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1493290892794, chunks=2, multiChunks=1, fileContents=2, fileHistories=2]
27-4-17 11:01:32.818 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
27-4-17 11:01:32.819 | UpOperation     | Test worker    | INFO : Last vector clock was: (A2)
27-4-17 11:01:32.819 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
27-4-17 11:01:32.819 | UpOperation     | Test worker    | INFO : - Uploading multichunk ae3a61fcfff78f7ead9c9522a6cae28e5e390983 from /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/multichunk-ae3a61fcfff78f7ead9c9522a6cae28e5e390983 to RemoteFile[name=multichunk-ae3a61fcfff78f7ead9c9522a6cae28e5e390983] ...
27-4-17 11:01:32.819 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/multichunk-ae3a61fcfff78f7ead9c9522a6cae28e5e390983 -> Temp. remote file: RemoteFile[name=temp-EsrHX-multichunk-ae3a61fcfff78f7ead9c9522a6cae28e5e390983], final location: RemoteFile[name=multichunk-ae3a61fcfff78f7ead9c9522a6cae28e5e390983]
27-4-17 11:01:32.819 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A3)/T=1493290892819, chunks=2, multiChunks=1, fileContents=2, fileHistories=2]
27-4-17 11:01:32.819 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A3)/T=1493290892819 to file /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-A-0000000003 ... 
27-4-17 11:01:32.820 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-A-0000000003 ...
27-4-17 11:01:32.820 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
27-4-17 11:01:32.820 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-A-0000000003 to RemoteFile[name=database-A-0000000003] ...
27-4-17 11:01:32.820 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-A-0000000003 -> Temp. remote file: RemoteFile[name=temp-gcsOr-database-A-0000000003], final location: RemoteFile[name=database-A-0000000003]
27-4-17 11:01:32.821 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
27-4-17 11:01:32.821 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
27-4-17 11:01:32.822 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/temp-transaction-5828465692091232688.tmp
27-4-17 11:01:32.822 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@178aa2f5) ...
27-4-17 11:01:32.822 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-9f2828e] ...
27-4-17 11:01:32.823 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
27-4-17 11:01:32.823 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@5bc7100e) ...
27-4-17 11:01:32.823 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/multichunk-ae3a61fcfff78f7ead9c9522a6cae28e5e390983 to temp. file RemoteFile[name=temp-EsrHX-multichunk-ae3a61fcfff78f7ead9c9522a6cae28e5e390983] ...
27-4-17 11:01:32.824 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@27e924ea) ...
27-4-17 11:01:32.824 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@95878b2) ...
27-4-17 11:01:32.824 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-A-0000000003 to temp. file RemoteFile[name=temp-gcsOr-database-A-0000000003] ...
27-4-17 11:01:32.825 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-EsrHX-multichunk-ae3a61fcfff78f7ead9c9522a6cae28e5e390983] to final location RemoteFile[name=multichunk-ae3a61fcfff78f7ead9c9522a6cae28e5e390983] ...
27-4-17 11:01:32.825 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-gcsOr-database-A-0000000003] to final location RemoteFile[name=database-A-0000000003] ...
27-4-17 11:01:32.825 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-9f2828e] ...
27-4-17 11:01:32.825 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
27-4-17 11:01:32.825 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
27-4-17 11:01:32.825 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A3)/T=1493290892819) ...
27-4-17 11:01:32.828 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
27-4-17 11:01:32.831 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
27-4-17 11:01:32.843 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A3)/T=1493290892819, chunks=2, multiChunks=1, fileContents=2, fileHistories=2]
27-4-17 11:01:32.843 | UpOperation     | Test worker    | INFO : Committing local database.
27-4-17 11:01:32.843 | UpOperation     | Test worker    | FINE : Waiting for new database version.
27-4-17 11:01:32.843 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1493290892835, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
27-4-17 11:01:32.843 | UpOperation     | Test worker    | INFO : Sync up done.
27-4-17 11:01:32.846 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1493290892779] ...
27-4-17 11:01:32.850 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1493290892779]
27-4-17 11:01:32.851 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
27-4-17 11:01:32.851 | Cache           | Test worker    | INFO : Cache size okay (154 KB), no need to clean (keep size is 500 MB)
27-4-17 11:01:32.851 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@236daf7d) ...
27-4-17 11:01:32.851 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:32.851 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-A' ...
27-4-17 11:01:32.851 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:32.851 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:32.851 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:32.851 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:32.851 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:32.851 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:32.851 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:32.852 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:32.852 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:32.852 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-A' ...
27-4-17 11:01:32.852 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:32.852 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:32.852 | TransferManager | Test worker    | INFO : - With feature PathAware
27-4-17 11:01:32.852 | TransferManager | Test worker    | INFO : - With feature TransactionAware
27-4-17 11:01:32.852 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:32.852 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:32.852 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:32.852 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:32.852 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:32.852 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:32.852 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
27-4-17 11:01:32.852 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
27-4-17 11:01:32.853 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:32.853 | UpOperation     | Test worker    | INFO : 
27-4-17 11:01:32.853 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
27-4-17 11:01:32.853 | UpOperation     | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:32.853 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@66fb2f7a) ...
27-4-17 11:01:32.853 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:32.853 | StatusOperation | Test worker    | INFO : 
27-4-17 11:01:32.853 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
27-4-17 11:01:32.853 | StatusOperation | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:32.853 | StatusOperation | Test worker    | INFO : Force checksum ENABLED.
27-4-17 11:01:32.853 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
27-4-17 11:01:32.853 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@3f320b87) ...
27-4-17 11:01:32.854 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-170427110008054-46179-client-A ...
27-4-17 11:01:32.854 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
27-4-17 11:01:32.855 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@5dfa2972) ...
27-4-17 11:01:32.855 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
27-4-17 11:01:32.855 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:32.855 | LsRemoteOperati | Test worker    | INFO : 
27-4-17 11:01:32.855 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
27-4-17 11:01:32.856 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:32.856 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@52f8eebc) ...
27-4-17 11:01:32.856 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
27-4-17 11:01:32.856 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
27-4-17 11:01:32.856 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
27-4-17 11:01:32.856 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
27-4-17 11:01:32.856 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@387cbb2d) ...
27-4-17 11:01:32.856 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
27-4-17 11:01:32.856 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-A-1493290892852] ...
27-4-17 11:01:32.856 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-A-1493290892852]
27-4-17 11:01:32.856 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-A-1493290892852] ...
27-4-17 11:01:32.857 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:32.861 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
27-4-17 11:01:32.862 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
27-4-17 11:01:32.862 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
27-4-17 11:01:32.866 | Indexer         | AsyncI/syncany | FINE :   + Deleted: Adding DELETED version: FileVersion [version=2, path=A3, type=FILE, status=DELETED, size=51200, lastModified=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=db017b97ff6e9e8df6c8ba9158064dd65824bc95, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
27-4-17 11:01:32.866 | Indexer         | AsyncI/syncany | FINE :                            based on: FileVersion [version=1, path=A3, type=FILE, status=NEW, size=51200, lastModified=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=db017b97ff6e9e8df6c8ba9158064dd65824bc95, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
27-4-17 11:01:32.866 | Indexer         | AsyncI/syncany | FINE : Added database version with only deletions: DatabaseVersion [header=UnknownMachine/()/T=1493290892862, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
27-4-17 11:01:32.866 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
27-4-17 11:01:32.867 | UpOperation     | Test worker    | INFO : Last vector clock was: (A3)
27-4-17 11:01:32.867 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
27-4-17 11:01:32.867 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=A/(A4)/T=1493290892867, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
27-4-17 11:01:32.867 | UpOperation     | Test worker    | INFO : Saving local delta database, version A/(A4)/T=1493290892867 to file /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-A-0000000004 ... 
27-4-17 11:01:32.867 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-A-0000000004 ...
27-4-17 11:01:32.868 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
27-4-17 11:01:32.868 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-A-0000000004 to RemoteFile[name=database-A-0000000004] ...
27-4-17 11:01:32.868 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-A-0000000004 -> Temp. remote file: RemoteFile[name=temp-LZuZV-database-A-0000000004], final location: RemoteFile[name=database-A-0000000004]
27-4-17 11:01:32.869 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
27-4-17 11:01:32.869 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
27-4-17 11:01:32.870 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/temp-transaction-5501386443769086122.tmp
27-4-17 11:01:32.870 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@2b9b013) ...
27-4-17 11:01:32.870 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-24cc3ffb] ...
27-4-17 11:01:32.871 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
27-4-17 11:01:32.871 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@7923163) ...
27-4-17 11:01:32.871 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-A-0000000004 to temp. file RemoteFile[name=temp-LZuZV-database-A-0000000004] ...
27-4-17 11:01:32.871 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-LZuZV-database-A-0000000004] to final location RemoteFile[name=database-A-0000000004] ...
27-4-17 11:01:32.871 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-24cc3ffb] ...
27-4-17 11:01:32.871 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
27-4-17 11:01:32.871 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
27-4-17 11:01:32.871 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version A/(A4)/T=1493290892867) ...
27-4-17 11:01:32.872 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
27-4-17 11:01:32.877 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
27-4-17 11:01:32.881 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=A/(A4)/T=1493290892867, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
27-4-17 11:01:32.881 | UpOperation     | Test worker    | INFO : Committing local database.
27-4-17 11:01:32.881 | UpOperation     | Test worker    | FINE : Waiting for new database version.
27-4-17 11:01:32.881 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1493290892877, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
27-4-17 11:01:32.882 | UpOperation     | Test worker    | INFO : Sync up done.
27-4-17 11:01:32.884 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-A-1493290892852] ...
27-4-17 11:01:32.889 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-A-1493290892852]
27-4-17 11:01:32.889 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
27-4-17 11:01:32.890 | Cache           | Test worker    | INFO : Cache size okay (155 KB), no need to clean (keep size is 500 MB)
27-4-17 11:01:32.890 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@f85c93) ...
27-4-17 11:01:32.890 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:32.890 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-B' ...
27-4-17 11:01:32.890 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:32.890 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:32.890 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:32.890 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:32.890 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:32.890 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:32.890 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:32.890 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:32.890 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:32.890 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-B' ...
27-4-17 11:01:32.890 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:32.890 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:32.890 | TransferManager | Test worker    | INFO : - With feature PathAware
27-4-17 11:01:32.890 | TransferManager | Test worker    | INFO : - With feature TransactionAware
27-4-17 11:01:32.890 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:32.891 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:32.891 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:32.891 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:32.891 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:32.891 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:32.891 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
27-4-17 11:01:32.891 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
27-4-17 11:01:32.914 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
27-4-17 11:01:32.914 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
27-4-17 11:01:32.923 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
27-4-17 11:01:32.926 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
27-4-17 11:01:32.926 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
27-4-17 11:01:32.932 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
27-4-17 11:01:32.932 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
27-4-17 11:01:32.932 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
27-4-17 11:01:32.932 | 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) ); 
27-4-17 11:01:32.936 | 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 ); 
27-4-17 11:01:32.942 | 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 ); 
27-4-17 11:01:32.944 | 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 ); 
27-4-17 11:01:32.947 | 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 ); 
27-4-17 11:01:32.949 | 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 ); 
27-4-17 11:01:32.952 | 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 ); 
27-4-17 11:01:32.955 | 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 ); 
27-4-17 11:01:32.957 | 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 ); 
27-4-17 11:01:32.960 | 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) ); 
27-4-17 11:01:32.963 | 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) ); 
27-4-17 11:01:32.966 | 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) ); 
27-4-17 11:01:32.969 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
27-4-17 11:01:32.969 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
27-4-17 11:01:32.969 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
27-4-17 11:01:32.972 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
27-4-17 11:01:32.974 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
27-4-17 11:01:32.976 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
27-4-17 11:01:32.979 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
27-4-17 11:01:32.981 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
27-4-17 11:01:32.983 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
27-4-17 11:01:32.983 | 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'; 
27-4-17 11:01:32.985 | 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'; 
27-4-17 11:01:32.988 | 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; 
27-4-17 11:01:32.993 | 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'; 
27-4-17 11:01:32.996 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
27-4-17 11:01:32.996 | 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; 
27-4-17 11:01:32.999 | 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; 
27-4-17 11:01:33.008 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
27-4-17 11:01:33.008 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
27-4-17 11:01:33.009 | 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; 
27-4-17 11:01:33.012 | DownOperation   | Test worker    | INFO : 
27-4-17 11:01:33.012 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
27-4-17 11:01:33.012 | DownOperation   | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.012 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@62d83f6f) ...
27-4-17 11:01:33.012 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
27-4-17 11:01:33.013 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.013 | LsRemoteOperati | Test worker    | INFO : 
27-4-17 11:01:33.013 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
27-4-17 11:01:33.013 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.013 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@64f63875) ...
27-4-17 11:01:33.013 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
27-4-17 11:01:33.013 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is new.
27-4-17 11:01:33.013 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
27-4-17 11:01:33.013 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is new.
27-4-17 11:01:33.013 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
27-4-17 11:01:33.013 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@746cf84) ...
27-4-17 11:01:33.013 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@5a63b526) ...
27-4-17 11:01:33.013 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1493290892891] ...
27-4-17 11:01:33.013 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1493290892891]
27-4-17 11:01:33.015 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1493290892891] ...
27-4-17 11:01:33.016 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
27-4-17 11:01:33.016 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000004 to local cache at /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/database-A-0000000004
27-4-17 11:01:33.016 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@2f26fcfa) ...
27-4-17 11:01:33.017 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000002 to local cache at /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/database-A-0000000002
27-4-17 11:01:33.022 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@68abb6bd) ...
27-4-17 11:01:33.025 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000003 to local cache at /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/database-A-0000000003
27-4-17 11:01:33.025 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@7f638744) ...
27-4-17 11:01:33.026 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000001 to local cache at /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/database-A-0000000001
27-4-17 11:01:33.026 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@86b6d76) ...
27-4-17 11:01:33.027 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
27-4-17 11:01:33.027 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/database-A-0000000001 ...
27-4-17 11:01:33.028 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1493290892691
27-4-17 11:01:33.028 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/database-A-0000000002 ...
27-4-17 11:01:33.034 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1493290892744
27-4-17 11:01:33.035 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/database-A-0000000003 ...
27-4-17 11:01:33.037 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A3)/T=1493290892819
27-4-17 11:01:33.037 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/database-A-0000000004 ...
27-4-17 11:01:33.039 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A4)/T=1493290892867
27-4-17 11:01:33.039 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.039 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.039 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.039 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.040 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
27-4-17 11:01:33.040 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1493290892691, A/(A2)/T=1493290892744, A/(A3)/T=1493290892819, A/(A4)/T=1493290892867], B=[]}
27-4-17 11:01:33.040 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
27-4-17 11:01:33.040 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1493290892691
27-4-17 11:01:33.040 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1493290892744
27-4-17 11:01:33.040 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3)/T=1493290892819
27-4-17 11:01:33.040 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A4)/T=1493290892867
27-4-17 11:01:33.040 | DatabaseReconci | Test worker    | INFO : - Winner is A with branch: 
27-4-17 11:01:33.040 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1493290892691
27-4-17 11:01:33.040 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1493290892744
27-4-17 11:01:33.040 | DatabaseReconci | Test worker    | INFO :   + A/(A3)/T=1493290892819
27-4-17 11:01:33.040 | DatabaseReconci | Test worker    | INFO :   + A/(A4)/T=1493290892867
27-4-17 11:01:33.040 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
27-4-17 11:01:33.040 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
27-4-17 11:01:33.040 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
27-4-17 11:01:33.040 | DatabaseReconci | Test worker    | INFO : Losers Branch: []
27-4-17 11:01:33.040 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1493290892691, A/(A2)/T=1493290892744, A/(A3)/T=1493290892819, A/(A4)/T=1493290892867]
27-4-17 11:01:33.040 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
27-4-17 11:01:33.040 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A1)/T=1493290892691, A/(A2)/T=1493290892744, A/(A3)/T=1493290892819, A/(A4)/T=1493290892867]
27-4-17 11:01:33.040 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
27-4-17 11:01:33.040 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/database-A-0000000001 ...
27-4-17 11:01:33.044 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1493290892691
27-4-17 11:01:33.044 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/database-A-0000000002 ...
27-4-17 11:01:33.047 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1493290892744
27-4-17 11:01:33.047 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/database-A-0000000003 ...
27-4-17 11:01:33.057 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A3)/T=1493290892819
27-4-17 11:01:33.057 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/database-A-0000000004 ...
27-4-17 11:01:33.062 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A4)/T=1493290892867
27-4-17 11:01:33.062 | DownOperation   | Test worker    | INFO : Determine file system actions ...
27-4-17 11:01:33.063 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.065 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
27-4-17 11:01:33.065 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
27-4-17 11:01:33.065 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
27-4-17 11:01:33.066 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=2, path=A3, type=FILE, status=DELETED, size=51200, lastModified=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=db017b97ff6e9e8df6c8ba9158064dd65824bc95, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
27-4-17 11:01:33.066 | FileVersionComp | Test worker    | INFO :      - []: Local file does not exist, and expected file was deleted, for file A3
27-4-17 11:01:33.066 | 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=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=db017b97ff6e9e8df6c8ba9158064dd65824bc95, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-170427110008054-46179-client-B/A3
27-4-17 11:01:33.066 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
27-4-17 11:01:33.066 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=6be7cf28a705f4ef3be486457ae0624fca1c4c20, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
27-4-17 11:01:33.068 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file A2
27-4-17 11:01:33.068 | 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=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=6be7cf28a705f4ef3be486457ae0624fca1c4c20, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-170427110008054-46179-client-B/A2
27-4-17 11:01:33.068 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=6be7cf28a705f4ef3be486457ae0624fca1c4c20, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
27-4-17 11:01:33.070 | DownOperation   | Test worker    | INFO :   + Adding multichunk ae3a61fcfff78f7ead9c9522a6cae28e5e390983 to download list ...
27-4-17 11:01:33.070 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
27-4-17 11:01:33.070 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@14aa0d55) ...
27-4-17 11:01:33.070 | Downloader      | Test worker    | INFO :   + Downloading multichunk ae3a61fcfff78f7ead9c9522a6cae28e5e390983 ...
27-4-17 11:01:33.072 | Downloader      | Test worker    | INFO :   + Decrypting multichunk ae3a61fcfff78f7ead9c9522a6cae28e5e390983 ...
27-4-17 11:01:33.072 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk ae3a61fcfff78f7ead9c9522a6cae28e5e390983 ...
27-4-17 11:01:33.081 | FileSystemActio | Test worker    | INFO :    Sorted actions:
27-4-17 11:01:33.081 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=6be7cf28a705f4ef3be486457ae0624fca1c4c20, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
27-4-17 11:01:33.082 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
27-4-17 11:01:33.082 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=6be7cf28a705f4ef3be486457ae0624fca1c4c20, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
27-4-17 11:01:33.083 | Assembler       | Test worker    | INFO :      - Creating file A2 to /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/temp-reconstructedFileVersion-1441910159241902153.tmp ...
27-4-17 11:01:33.085 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
27-4-17 11:01:33.085 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
27-4-17 11:01:33.085 | DownOperation   | Test worker    | INFO :   + Applying database version (A1)
27-4-17 11:01:33.085 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A1)/T=1493290892691, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
27-4-17 11:01:33.088 | DownOperation   | Test worker    | INFO :   + Applying database version (A2)
27-4-17 11:01:33.088 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A2)/T=1493290892744, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
27-4-17 11:01:33.088 | DownOperation   | Test worker    | INFO :   + Applying database version (A3)
27-4-17 11:01:33.088 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A3)/T=1493290892819, chunks=2, multiChunks=1, fileContents=2, fileHistories=2]
27-4-17 11:01:33.093 | DownOperation   | Test worker    | INFO :   + Applying database version (A4)
27-4-17 11:01:33.093 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A4)/T=1493290892867, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
27-4-17 11:01:33.103 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1493290892891] ...
27-4-17 11:01:33.109 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1493290892891]
27-4-17 11:01:33.109 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
27-4-17 11:01:33.110 | Cache           | Test worker    | INFO : Cache size okay (104 KB), no need to clean (keep size is 500 MB)
27-4-17 11:01:33.110 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@7b3de53c) ...
27-4-17 11:01:33.110 | DownOperation   | Test worker    | INFO : Sync down done.
27-4-17 11:01:33.113 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-170427110008054-46179-client-A/A2, but actual PATH = tmp/syncanytest/syncany-170427110008054-46179-client-B/A2, for file tmp/syncanytest/syncany-170427110008054-46179-client-B/A2
27-4-17 11:01:33.114 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.114 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-B' ...
27-4-17 11:01:33.114 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.114 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.114 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.114 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.114 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.114 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.114 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.114 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.114 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.114 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-B' ...
27-4-17 11:01:33.114 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.114 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.114 | TransferManager | Test worker    | INFO : - With feature PathAware
27-4-17 11:01:33.114 | TransferManager | Test worker    | INFO : - With feature TransactionAware
27-4-17 11:01:33.114 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.114 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.114 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.115 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.115 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.115 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.115 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
27-4-17 11:01:33.115 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
27-4-17 11:01:33.116 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.116 | UpOperation     | Test worker    | INFO : 
27-4-17 11:01:33.116 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client B ...
27-4-17 11:01:33.116 | UpOperation     | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.116 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@9cd3116) ...
27-4-17 11:01:33.117 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.117 | StatusOperation | Test worker    | INFO : 
27-4-17 11:01:33.117 | StatusOperation | Test worker    | INFO : Running 'Status' at client B ...
27-4-17 11:01:33.117 | StatusOperation | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.117 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
27-4-17 11:01:33.117 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@61b38924) ...
27-4-17 11:01:33.118 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-170427110008054-46179-client-B ...
27-4-17 11:01:33.118 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
27-4-17 11:01:33.119 | StatusOperation | Test worker    | FINE : - New file: A4,B1
27-4-17 11:01:33.119 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@2284ceb7) ...
27-4-17 11:01:33.119 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
27-4-17 11:01:33.121 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.121 | LsRemoteOperati | Test worker    | INFO : 
27-4-17 11:01:33.121 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
27-4-17 11:01:33.122 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.122 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@2c3e76d0) ...
27-4-17 11:01:33.122 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
27-4-17 11:01:33.122 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
27-4-17 11:01:33.122 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
27-4-17 11:01:33.122 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
27-4-17 11:01:33.122 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
27-4-17 11:01:33.122 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@bb6e158) ...
27-4-17 11:01:33.122 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
27-4-17 11:01:33.122 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-B-1493290893115] ...
27-4-17 11:01:33.122 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-B-1493290893115]
27-4-17 11:01:33.122 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-B-1493290893115] ...
27-4-17 11:01:33.128 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.153 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
27-4-17 11:01:33.160 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
27-4-17 11:01:33.160 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@5958ac8f) ...
27-4-17 11:01:33.160 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
27-4-17 11:01:33.160 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-170427110008054-46179-client-B/A4,B1
27-4-17 11:01:33.160 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-170427110008054-46179-client-B/A4,B1
27-4-17 11:01:33.162 | Indexer         | AsyncI/syncany | FINE : - Chunk new: 2a355a2b2b4bbac69e38a6c1b370782d125b1245
27-4-17 11:01:33.162 | Indexer         | AsyncI/syncany | FINE : - +MultiChunk b3cf40bc12f6ec5d06c12d2befe52e2c8703c945
27-4-17 11:01:33.163 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: 2a355a2b2b4bbac69e38a6c1b370782d125b1245 > b3cf40bc12f6ec5d06c12d2befe52e2c8703c945
27-4-17 11:01:33.163 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 2a355a2b2b4bbac69e38a6c1b370782d125b1245 > /tmp/syncanytest/syncany-170427110008054-46179-client-B/A4,B1
27-4-17 11:01:33.163 | Indexer         | AsyncI/syncany | FINE : - /File: A4,B1 (checksum 2a355a2b2b4bbac69e38a6c1b370782d125b1245)
27-4-17 11:01:33.164 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: A4,B1, checksum: 2a355a2b2b4bbac69e38a6c1b370782d125b1245)
27-4-17 11:01:33.164 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file A4,B1
27-4-17 11:01:33.164 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Thu Apr 27 11:01:33 UTC 2017, linkTarget=null, checksum=2a355a2b2b4bbac69e38a6c1b370782d125b1245, updated=Thu Apr 27 11:01:33 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
27-4-17 11:01:33.164 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
27-4-17 11:01:33.164 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@4d0fb8ce) ...
27-4-17 11:01:33.165 | Indexer         | AsyncI/syncany | FINE : - /MultiChunk b3cf40bc12f6ec5d06c12d2befe52e2c8703c945
27-4-17 11:01:33.165 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@48b01629) ...
27-4-17 11:01:33.165 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1493290893160, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
27-4-17 11:01:33.165 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
27-4-17 11:01:33.165 | UpOperation     | Test worker    | INFO : Last vector clock was: (A4)
27-4-17 11:01:33.165 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
27-4-17 11:01:33.165 | UpOperation     | Test worker    | INFO : - Uploading multichunk b3cf40bc12f6ec5d06c12d2befe52e2c8703c945 from /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/multichunk-b3cf40bc12f6ec5d06c12d2befe52e2c8703c945 to RemoteFile[name=multichunk-b3cf40bc12f6ec5d06c12d2befe52e2c8703c945] ...
27-4-17 11:01:33.166 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/multichunk-b3cf40bc12f6ec5d06c12d2befe52e2c8703c945 -> Temp. remote file: RemoteFile[name=temp-JTybC-multichunk-b3cf40bc12f6ec5d06c12d2befe52e2c8703c945], final location: RemoteFile[name=multichunk-b3cf40bc12f6ec5d06c12d2befe52e2c8703c945]
27-4-17 11:01:33.166 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=B/(A4,B1)/T=1493290893165, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
27-4-17 11:01:33.166 | UpOperation     | Test worker    | INFO : Saving local delta database, version B/(A4,B1)/T=1493290893165 to file /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/database-B-0000000001 ... 
27-4-17 11:01:33.166 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/database-B-0000000001 ...
27-4-17 11:01:33.167 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
27-4-17 11:01:33.167 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/database-B-0000000001 to RemoteFile[name=database-B-0000000001] ...
27-4-17 11:01:33.167 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/database-B-0000000001 -> Temp. remote file: RemoteFile[name=temp-PSZNy-database-B-0000000001], final location: RemoteFile[name=database-B-0000000001]
27-4-17 11:01:33.167 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
27-4-17 11:01:33.167 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
27-4-17 11:01:33.168 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/temp-transaction-2317593175754840445.tmp
27-4-17 11:01:33.169 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@117fbd1e) ...
27-4-17 11:01:33.169 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-304e9506] ...
27-4-17 11:01:33.169 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
27-4-17 11:01:33.169 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@652d122c) ...
27-4-17 11:01:33.169 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/multichunk-b3cf40bc12f6ec5d06c12d2befe52e2c8703c945 to temp. file RemoteFile[name=temp-JTybC-multichunk-b3cf40bc12f6ec5d06c12d2befe52e2c8703c945] ...
27-4-17 11:01:33.169 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@765aab90) ...
27-4-17 11:01:33.169 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/database-B-0000000001 to temp. file RemoteFile[name=temp-PSZNy-database-B-0000000001] ...
27-4-17 11:01:33.170 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-JTybC-multichunk-b3cf40bc12f6ec5d06c12d2befe52e2c8703c945] to final location RemoteFile[name=multichunk-b3cf40bc12f6ec5d06c12d2befe52e2c8703c945] ...
27-4-17 11:01:33.170 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-PSZNy-database-B-0000000001] to final location RemoteFile[name=database-B-0000000001] ...
27-4-17 11:01:33.170 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-304e9506] ...
27-4-17 11:01:33.170 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
27-4-17 11:01:33.170 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
27-4-17 11:01:33.170 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version B/(A4,B1)/T=1493290893165) ...
27-4-17 11:01:33.172 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
27-4-17 11:01:33.169 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@5ebf529d) ...
27-4-17 11:01:33.184 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=B/(A4,B1)/T=1493290893165, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
27-4-17 11:01:33.184 | UpOperation     | Test worker    | INFO : Committing local database.
27-4-17 11:01:33.184 | UpOperation     | Test worker    | FINE : Waiting for new database version.
27-4-17 11:01:33.187 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
27-4-17 11:01:33.187 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1493290893187, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
27-4-17 11:01:33.187 | UpOperation     | Test worker    | INFO : Sync up done.
27-4-17 11:01:33.189 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-B-1493290893115] ...
27-4-17 11:01:33.193 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-B-1493290893115]
27-4-17 11:01:33.193 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
27-4-17 11:01:33.194 | Cache           | Test worker    | INFO : Cache size okay (156 KB), no need to clean (keep size is 500 MB)
27-4-17 11:01:33.194 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@ce79231) ...
27-4-17 11:01:33.194 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.194 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-C' ...
27-4-17 11:01:33.194 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.194 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.194 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.195 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.195 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.195 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.195 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.195 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.195 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.195 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-C' ...
27-4-17 11:01:33.195 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.195 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.195 | TransferManager | Test worker    | INFO : - With feature PathAware
27-4-17 11:01:33.195 | TransferManager | Test worker    | INFO : - With feature TransactionAware
27-4-17 11:01:33.195 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.195 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.195 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.195 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.195 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.195 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.195 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
27-4-17 11:01:33.195 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
27-4-17 11:01:33.215 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint start
27-4-17 11:01:33.215 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose start
27-4-17 11:01:33.222 | hsqldb.db.HSQLD | Test worker    | FINE : log close size: 0
27-4-17 11:01:33.224 | hsqldb.db.HSQLD | Test worker    | INFO : checkpointClose end
27-4-17 11:01:33.224 | hsqldb.db.HSQLD | Test worker    | INFO : Checkpoint end - txts: 1
27-4-17 11:01:33.229 | DatabaseConnect | Test worker    | INFO : Found 0 tables.
27-4-17 11:01:33.229 | DatabaseConnect | Test worker    | INFO : Database has no tables. Creating tables from script.create.all.sql
27-4-17 11:01:33.230 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Tables
27-4-17 11:01:33.230 | 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) ); 
27-4-17 11:01:33.233 | 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 ); 
27-4-17 11:01:33.235 | 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 ); 
27-4-17 11:01:33.238 | 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 ); 
27-4-17 11:01:33.240 | 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 ); 
27-4-17 11:01:33.242 | 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 ); 
27-4-17 11:01:33.244 | 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 ); 
27-4-17 11:01:33.247 | 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 ); 
27-4-17 11:01:33.249 | 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 ); 
27-4-17 11:01:33.251 | 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) ); 
27-4-17 11:01:33.253 | 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) ); 
27-4-17 11:01:33.255 | 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) ); 
27-4-17 11:01:33.258 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Non-primary indices
27-4-17 11:01:33.258 | SqlRunner       | Test worker    | INFO : SQL:   CREATE INDEX idx_databaseversion_status ON databaseversion (status); 
27-4-17 11:01:33.259 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open start
27-4-17 11:01:33.262 | hsqldb.db.HSQLD | Test worker    | INFO : dataFileCache open end
27-4-17 11:01:33.264 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_databaseversion_vectorclock_serialized ON databaseversion (vectorclock_serialized); 
27-4-17 11:01:33.268 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_path ON fileversion (path); 
27-4-17 11:01:33.273 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_status ON fileversion (status); 
27-4-17 11:01:33.275 | SqlRunner       | Test worker    | INFO : SQL: CREATE INDEX idx_fileversion_filecontent_checksum ON fileversion (filecontent_checksum); 
27-4-17 11:01:33.277 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Views
27-4-17 11:01:33.277 | 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'; 
27-4-17 11:01:33.280 | 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'; 
27-4-17 11:01:33.283 | 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; 
27-4-17 11:01:33.287 | 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'; 
27-4-17 11:01:33.290 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Full Views
27-4-17 11:01:33.290 | 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; 
27-4-17 11:01:33.292 | 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; 
27-4-17 11:01:33.295 | SqlRunner       | Test worker    | INFO : SQL (comment): -- Functions
27-4-17 11:01:33.295 | SqlRunner       | Test worker    | INFO : SQL (new delimiter): end;
27-4-17 11:01:33.295 | 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; 
27-4-17 11:01:33.299 | UpOperation     | Test worker    | INFO : 
27-4-17 11:01:33.299 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client C ...
27-4-17 11:01:33.299 | UpOperation     | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.299 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@3bdcb92b) ...
27-4-17 11:01:33.299 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.299 | StatusOperation | Test worker    | INFO : 
27-4-17 11:01:33.299 | StatusOperation | Test worker    | INFO : Running 'Status' at client C ...
27-4-17 11:01:33.299 | StatusOperation | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.299 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
27-4-17 11:01:33.299 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@460b1298) ...
27-4-17 11:01:33.300 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-170427110008054-46179-client-C ...
27-4-17 11:01:33.300 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
27-4-17 11:01:33.300 | StatusOperation | Test worker    | FINE : - New file: C1
27-4-17 11:01:33.300 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@2821649) ...
27-4-17 11:01:33.300 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
27-4-17 11:01:33.301 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.301 | LsRemoteOperati | Test worker    | INFO : 
27-4-17 11:01:33.301 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
27-4-17 11:01:33.301 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.301 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@1d876e5) ...
27-4-17 11:01:33.304 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
27-4-17 11:01:33.304 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is new.
27-4-17 11:01:33.304 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
27-4-17 11:01:33.304 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is new.
27-4-17 11:01:33.304 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is new.
27-4-17 11:01:33.304 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
27-4-17 11:01:33.304 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@7a69064d) ...
27-4-17 11:01:33.304 | UpOperation     | Test worker    | INFO : There are remote changes. Call 'down' first or use --force-upload you must, Luke!
27-4-17 11:01:33.304 | 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-B-0000000001], RemoteFile[name=database-A-0000000001]]
27-4-17 11:01:33.304 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@79473be6) ...
27-4-17 11:01:33.305 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.305 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-C' ...
27-4-17 11:01:33.305 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.305 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.305 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.305 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.305 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.306 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.306 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.306 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.306 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.306 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-C' ...
27-4-17 11:01:33.306 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.306 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.306 | TransferManager | Test worker    | INFO : - With feature PathAware
27-4-17 11:01:33.306 | TransferManager | Test worker    | INFO : - With feature TransactionAware
27-4-17 11:01:33.306 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.306 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.306 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.306 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.306 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.306 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.306 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
27-4-17 11:01:33.306 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
27-4-17 11:01:33.312 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.312 | UpOperation     | Test worker    | INFO : 
27-4-17 11:01:33.312 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client C ...
27-4-17 11:01:33.312 | UpOperation     | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.312 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@8b80e36) ...
27-4-17 11:01:33.312 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.312 | StatusOperation | Test worker    | INFO : 
27-4-17 11:01:33.312 | StatusOperation | Test worker    | INFO : Running 'Status' at client C ...
27-4-17 11:01:33.312 | StatusOperation | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.312 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
27-4-17 11:01:33.312 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@7a09aeb5) ...
27-4-17 11:01:33.313 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-170427110008054-46179-client-C ...
27-4-17 11:01:33.313 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
27-4-17 11:01:33.313 | StatusOperation | Test worker    | FINE : - New file: C1
27-4-17 11:01:33.313 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@481bc0d2) ...
27-4-17 11:01:33.313 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
27-4-17 11:01:33.314 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.314 | LsRemoteOperati | Test worker    | INFO : 
27-4-17 11:01:33.314 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
27-4-17 11:01:33.314 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.314 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@5be14831) ...
27-4-17 11:01:33.314 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
27-4-17 11:01:33.314 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is new.
27-4-17 11:01:33.314 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
27-4-17 11:01:33.314 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is new.
27-4-17 11:01:33.314 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is new.
27-4-17 11:01:33.314 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
27-4-17 11:01:33.314 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@4ac1a98a) ...
27-4-17 11:01:33.315 | UpOperation     | Test worker    | INFO : There are remote changes. Call 'down' first or use --force-upload you must, Luke!
27-4-17 11:01:33.315 | 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-B-0000000001], RemoteFile[name=database-A-0000000001]]
27-4-17 11:01:33.315 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@3112bf32) ...
27-4-17 11:01:33.315 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.315 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-C' ...
27-4-17 11:01:33.315 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.315 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.315 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.315 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.315 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.315 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.315 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.315 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.315 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.315 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-C' ...
27-4-17 11:01:33.316 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.316 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.316 | TransferManager | Test worker    | INFO : - With feature PathAware
27-4-17 11:01:33.316 | TransferManager | Test worker    | INFO : - With feature TransactionAware
27-4-17 11:01:33.316 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.316 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.316 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.316 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.316 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.316 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.316 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
27-4-17 11:01:33.316 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
27-4-17 11:01:33.330 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.330 | UpOperation     | Test worker    | INFO : 
27-4-17 11:01:33.330 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client C ...
27-4-17 11:01:33.330 | UpOperation     | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.330 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@6b5e148b) ...
27-4-17 11:01:33.331 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.331 | StatusOperation | Test worker    | INFO : 
27-4-17 11:01:33.331 | StatusOperation | Test worker    | INFO : Running 'Status' at client C ...
27-4-17 11:01:33.331 | StatusOperation | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.331 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
27-4-17 11:01:33.331 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@85bbc0c) ...
27-4-17 11:01:33.331 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-170427110008054-46179-client-C ...
27-4-17 11:01:33.332 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
27-4-17 11:01:33.332 | StatusOperation | Test worker    | FINE : - New file: C1
27-4-17 11:01:33.332 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@1300b90d) ...
27-4-17 11:01:33.332 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
27-4-17 11:01:33.332 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.332 | LsRemoteOperati | Test worker    | INFO : 
27-4-17 11:01:33.332 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
27-4-17 11:01:33.332 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.332 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@1726fc0) ...
27-4-17 11:01:33.332 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
27-4-17 11:01:33.333 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is new.
27-4-17 11:01:33.333 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
27-4-17 11:01:33.333 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is new.
27-4-17 11:01:33.333 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is new.
27-4-17 11:01:33.333 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
27-4-17 11:01:33.333 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@79d2beb8) ...
27-4-17 11:01:33.333 | UpOperation     | Test worker    | INFO : There are remote changes. Call 'down' first or use --force-upload you must, Luke!
27-4-17 11:01:33.333 | 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-B-0000000001], RemoteFile[name=database-A-0000000001]]
27-4-17 11:01:33.333 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@23cabaac) ...
27-4-17 11:01:33.333 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.333 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-A' ...
27-4-17 11:01:33.333 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.333 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.333 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.333 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.333 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.333 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.334 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.334 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.334 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.334 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-A' ...
27-4-17 11:01:33.334 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.334 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.334 | TransferManager | Test worker    | INFO : - With feature PathAware
27-4-17 11:01:33.334 | TransferManager | Test worker    | INFO : - With feature TransactionAware
27-4-17 11:01:33.334 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.334 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.334 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.334 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.334 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.334 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.334 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
27-4-17 11:01:33.334 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
27-4-17 11:01:33.338 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.338 | DownOperation   | Test worker    | INFO : 
27-4-17 11:01:33.338 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client A ...
27-4-17 11:01:33.338 | DownOperation   | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.338 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@3b8681d7) ...
27-4-17 11:01:33.338 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
27-4-17 11:01:33.339 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.339 | LsRemoteOperati | Test worker    | INFO : 
27-4-17 11:01:33.339 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
27-4-17 11:01:33.339 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.339 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@212400fe) ...
27-4-17 11:01:33.339 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
27-4-17 11:01:33.339 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
27-4-17 11:01:33.340 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
27-4-17 11:01:33.340 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
27-4-17 11:01:33.340 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is new.
27-4-17 11:01:33.340 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
27-4-17 11:01:33.340 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@390b0192) ...
27-4-17 11:01:33.340 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@47705) ...
27-4-17 11:01:33.340 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-A-1493290893334] ...
27-4-17 11:01:33.340 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-A-1493290893334]
27-4-17 11:01:33.340 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-A-1493290893334] ...
27-4-17 11:01:33.340 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
27-4-17 11:01:33.341 | DownOperation   | Test worker    | INFO : - Downloading database-B-0000000001 to local cache at /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-B-0000000001
27-4-17 11:01:33.341 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@332a5f06) ...
27-4-17 11:01:33.341 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
27-4-17 11:01:33.341 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-B-0000000001 ...
27-4-17 11:01:33.342 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A4,B1)/T=1493290893165
27-4-17 11:01:33.343 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.343 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.348 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.348 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.348 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.348 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
27-4-17 11:01:33.349 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1493290892691, A/(A2)/T=1493290892744, A/(A3)/T=1493290892819, A/(A4)/T=1493290892867], B=[B/(A4,B1)/T=1493290893165]}
27-4-17 11:01:33.349 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
27-4-17 11:01:33.349 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1493290892691
27-4-17 11:01:33.349 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1493290892744
27-4-17 11:01:33.349 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3)/T=1493290892819
27-4-17 11:01:33.349 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A4)/T=1493290892867
27-4-17 11:01:33.349 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A4,B1)/T=1493290893165
27-4-17 11:01:33.349 | DatabaseReconci | Test worker    | INFO : - Winner is B with branch: 
27-4-17 11:01:33.349 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1493290892691
27-4-17 11:01:33.349 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1493290892744
27-4-17 11:01:33.349 | DatabaseReconci | Test worker    | INFO :   + A/(A3)/T=1493290892819
27-4-17 11:01:33.349 | DatabaseReconci | Test worker    | INFO :   + A/(A4)/T=1493290892867
27-4-17 11:01:33.349 | DatabaseReconci | Test worker    | INFO :   + B/(A4,B1)/T=1493290893165
27-4-17 11:01:33.349 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
27-4-17 11:01:33.349 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
27-4-17 11:01:33.349 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
27-4-17 11:01:33.349 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1493290892691, A/(A2)/T=1493290892744, A/(A3)/T=1493290892819, A/(A4)/T=1493290892867]
27-4-17 11:01:33.349 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1493290892691, A/(A2)/T=1493290892744, A/(A3)/T=1493290892819, A/(A4)/T=1493290892867, B/(A4,B1)/T=1493290893165]
27-4-17 11:01:33.349 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
27-4-17 11:01:33.349 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [B/(A4,B1)/T=1493290893165]
27-4-17 11:01:33.349 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
27-4-17 11:01:33.350 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-B-0000000001 ...
27-4-17 11:01:33.351 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A4,B1)/T=1493290893165
27-4-17 11:01:33.351 | DownOperation   | Test worker    | INFO : Determine file system actions ...
27-4-17 11:01:33.352 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.353 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
27-4-17 11:01:33.353 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
27-4-17 11:01:33.353 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
27-4-17 11:01:33.353 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Thu Apr 27 11:01:33 UTC 2017, linkTarget=null, checksum=2a355a2b2b4bbac69e38a6c1b370782d125b1245, updated=Thu Apr 27 11:01:33 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
27-4-17 11:01:33.354 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file A4,B1
27-4-17 11:01:33.354 | 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=Thu Apr 27 11:01:33 UTC 2017, linkTarget=null, checksum=2a355a2b2b4bbac69e38a6c1b370782d125b1245, updated=Thu Apr 27 11:01:33 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-170427110008054-46179-client-A/A4,B1
27-4-17 11:01:33.358 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Thu Apr 27 11:01:33 UTC 2017, linkTarget=null, checksum=2a355a2b2b4bbac69e38a6c1b370782d125b1245, updated=Thu Apr 27 11:01:33 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
27-4-17 11:01:33.358 | DownOperation   | Test worker    | INFO :   + Adding multichunk b3cf40bc12f6ec5d06c12d2befe52e2c8703c945 to download list ...
27-4-17 11:01:33.359 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
27-4-17 11:01:33.359 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@232c8e7c) ...
27-4-17 11:01:33.359 | Downloader      | Test worker    | INFO :   + Downloading multichunk b3cf40bc12f6ec5d06c12d2befe52e2c8703c945 ...
27-4-17 11:01:33.360 | Downloader      | Test worker    | INFO :   + Decrypting multichunk b3cf40bc12f6ec5d06c12d2befe52e2c8703c945 ...
27-4-17 11:01:33.360 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk b3cf40bc12f6ec5d06c12d2befe52e2c8703c945 ...
27-4-17 11:01:33.361 | FileSystemActio | Test worker    | INFO :    Sorted actions:
27-4-17 11:01:33.361 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Thu Apr 27 11:01:33 UTC 2017, linkTarget=null, checksum=2a355a2b2b4bbac69e38a6c1b370782d125b1245, updated=Thu Apr 27 11:01:33 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
27-4-17 11:01:33.361 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
27-4-17 11:01:33.361 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Thu Apr 27 11:01:33 UTC 2017, linkTarget=null, checksum=2a355a2b2b4bbac69e38a6c1b370782d125b1245, updated=Thu Apr 27 11:01:33 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
27-4-17 11:01:33.361 | Assembler       | Test worker    | INFO :      - Creating file A4,B1 to /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/temp-reconstructedFileVersion-6157136812238793133.tmp ...
27-4-17 11:01:33.362 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
27-4-17 11:01:33.363 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
27-4-17 11:01:33.363 | DownOperation   | Test worker    | INFO :   + Applying database version (A4,B1)
27-4-17 11:01:33.363 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=B/(A4,B1)/T=1493290893165, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
27-4-17 11:01:33.378 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-A-1493290893334] ...
27-4-17 11:01:33.384 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-A-1493290893334]
27-4-17 11:01:33.384 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
27-4-17 11:01:33.384 | Cache           | Test worker    | INFO : Cache size okay (206 KB), no need to clean (keep size is 500 MB)
27-4-17 11:01:33.385 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@24ddb9b2) ...
27-4-17 11:01:33.385 | DownOperation   | Test worker    | INFO : Sync down done.
27-4-17 11:01:33.390 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-170427110008054-46179-client-A/A2, but actual PATH = tmp/syncanytest/syncany-170427110008054-46179-client-B/A2, for file tmp/syncanytest/syncany-170427110008054-46179-client-B/A2
27-4-17 11:01:33.393 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-170427110008054-46179-client-A/A4,B1, but actual PATH = tmp/syncanytest/syncany-170427110008054-46179-client-B/A4,B1, for file tmp/syncanytest/syncany-170427110008054-46179-client-B/A4,B1
27-4-17 11:01:33.395 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.395 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-B' ...
27-4-17 11:01:33.395 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.395 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.395 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.395 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.395 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.395 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.395 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.395 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.395 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.395 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-B' ...
27-4-17 11:01:33.395 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.395 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.395 | TransferManager | Test worker    | INFO : - With feature PathAware
27-4-17 11:01:33.395 | TransferManager | Test worker    | INFO : - With feature TransactionAware
27-4-17 11:01:33.395 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.395 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.395 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.395 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.395 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.396 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.396 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
27-4-17 11:01:33.396 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
27-4-17 11:01:33.404 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.404 | DownOperation   | Test worker    | INFO : 
27-4-17 11:01:33.404 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
27-4-17 11:01:33.404 | DownOperation   | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.404 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@6b6f0443) ...
27-4-17 11:01:33.404 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
27-4-17 11:01:33.405 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.405 | LsRemoteOperati | Test worker    | INFO : 
27-4-17 11:01:33.406 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
27-4-17 11:01:33.406 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.406 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@41fa23b8) ...
27-4-17 11:01:33.406 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
27-4-17 11:01:33.407 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
27-4-17 11:01:33.407 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
27-4-17 11:01:33.407 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
27-4-17 11:01:33.407 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
27-4-17 11:01:33.407 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
27-4-17 11:01:33.407 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@1720a08) ...
27-4-17 11:01:33.407 | DownOperation   | Test worker    | INFO : * Nothing new. Skipping down operation.
27-4-17 11:01:33.407 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@111853a2) ...
27-4-17 11:01:33.414 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.416 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-C' ...
27-4-17 11:01:33.416 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.416 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.416 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.416 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.416 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.416 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.416 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.416 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.417 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.417 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-C' ...
27-4-17 11:01:33.417 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.417 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.417 | TransferManager | Test worker    | INFO : - With feature PathAware
27-4-17 11:01:33.417 | TransferManager | Test worker    | INFO : - With feature TransactionAware
27-4-17 11:01:33.417 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.417 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.417 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.417 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.417 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.417 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.417 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
27-4-17 11:01:33.417 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
27-4-17 11:01:33.419 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.419 | DownOperation   | Test worker    | INFO : 
27-4-17 11:01:33.419 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client C ...
27-4-17 11:01:33.419 | DownOperation   | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.419 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@717be82c) ...
27-4-17 11:01:33.419 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
27-4-17 11:01:33.421 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.421 | LsRemoteOperati | Test worker    | INFO : 
27-4-17 11:01:33.421 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
27-4-17 11:01:33.421 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.421 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@331e44a9) ...
27-4-17 11:01:33.422 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
27-4-17 11:01:33.422 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is new.
27-4-17 11:01:33.422 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is new.
27-4-17 11:01:33.422 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is new.
27-4-17 11:01:33.422 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is new.
27-4-17 11:01:33.422 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is new.
27-4-17 11:01:33.422 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@66303d35) ...
27-4-17 11:01:33.422 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@422e1d24) ...
27-4-17 11:01:33.422 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-C-1493290893418] ...
27-4-17 11:01:33.422 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-C-1493290893418]
27-4-17 11:01:33.423 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-C-1493290893418] ...
27-4-17 11:01:33.424 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
27-4-17 11:01:33.424 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000004 to local cache at /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/database-A-0000000004
27-4-17 11:01:33.424 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@8964d50) ...
27-4-17 11:01:33.425 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000002 to local cache at /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/database-A-0000000002
27-4-17 11:01:33.425 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@3ae3a65b) ...
27-4-17 11:01:33.429 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000003 to local cache at /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/database-A-0000000003
27-4-17 11:01:33.429 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@1803f1d1) ...
27-4-17 11:01:33.429 | DownOperation   | Test worker    | INFO : - Downloading database-B-0000000001 to local cache at /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/database-B-0000000001
27-4-17 11:01:33.429 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@37e40ef0) ...
27-4-17 11:01:33.430 | DownOperation   | Test worker    | INFO : - Downloading database-A-0000000001 to local cache at /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/database-A-0000000001
27-4-17 11:01:33.430 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@d222991) ...
27-4-17 11:01:33.431 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
27-4-17 11:01:33.431 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/database-A-0000000001 ...
27-4-17 11:01:33.433 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1493290892691
27-4-17 11:01:33.433 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/database-A-0000000002 ...
27-4-17 11:01:33.434 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1493290892744
27-4-17 11:01:33.435 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/database-A-0000000003 ...
27-4-17 11:01:33.437 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A3)/T=1493290892819
27-4-17 11:01:33.438 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/database-A-0000000004 ...
27-4-17 11:01:33.440 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A4)/T=1493290892867
27-4-17 11:01:33.440 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/database-B-0000000001 ...
27-4-17 11:01:33.442 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A4,B1)/T=1493290893165
27-4-17 11:01:33.443 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.443 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.443 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.443 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.443 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.445 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
27-4-17 11:01:33.445 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1493290892691, A/(A2)/T=1493290892744, A/(A3)/T=1493290892819, A/(A4)/T=1493290892867], B=[B/(A4,B1)/T=1493290893165], C=[]}
27-4-17 11:01:33.445 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
27-4-17 11:01:33.445 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1493290892691
27-4-17 11:01:33.445 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1493290892744
27-4-17 11:01:33.445 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3)/T=1493290892819
27-4-17 11:01:33.445 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A4)/T=1493290892867
27-4-17 11:01:33.445 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A4,B1)/T=1493290893165
27-4-17 11:01:33.445 | DatabaseReconci | Test worker    | INFO : - Winner is B with branch: 
27-4-17 11:01:33.445 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1493290892691
27-4-17 11:01:33.445 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1493290892744
27-4-17 11:01:33.445 | DatabaseReconci | Test worker    | INFO :   + A/(A3)/T=1493290892819
27-4-17 11:01:33.445 | DatabaseReconci | Test worker    | INFO :   + A/(A4)/T=1493290892867
27-4-17 11:01:33.445 | DatabaseReconci | Test worker    | INFO :   + B/(A4,B1)/T=1493290893165
27-4-17 11:01:33.445 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
27-4-17 11:01:33.445 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
27-4-17 11:01:33.445 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
27-4-17 11:01:33.445 | DatabaseReconci | Test worker    | INFO : Losers Branch: []
27-4-17 11:01:33.445 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1493290892691, A/(A2)/T=1493290892744, A/(A3)/T=1493290892819, A/(A4)/T=1493290892867, B/(A4,B1)/T=1493290893165]
27-4-17 11:01:33.445 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
27-4-17 11:01:33.445 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [A/(A1)/T=1493290892691, A/(A2)/T=1493290892744, A/(A3)/T=1493290892819, A/(A4)/T=1493290892867, B/(A4,B1)/T=1493290893165]
27-4-17 11:01:33.445 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
27-4-17 11:01:33.446 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/database-A-0000000001 ...
27-4-17 11:01:33.447 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A1)/T=1493290892691
27-4-17 11:01:33.447 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/database-A-0000000002 ...
27-4-17 11:01:33.451 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A2)/T=1493290892744
27-4-17 11:01:33.452 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/database-A-0000000003 ...
27-4-17 11:01:33.453 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A3)/T=1493290892819
27-4-17 11:01:33.454 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/database-A-0000000004 ...
27-4-17 11:01:33.454 | DatabaseXmlPars | Test worker    | INFO :    + Added database version A/(A4)/T=1493290892867
27-4-17 11:01:33.454 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/database-B-0000000001 ...
27-4-17 11:01:33.455 | DatabaseXmlPars | Test worker    | INFO :    + Added database version B/(A4,B1)/T=1493290893165
27-4-17 11:01:33.455 | DownOperation   | Test worker    | INFO : Determine file system actions ...
27-4-17 11:01:33.461 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.462 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
27-4-17 11:01:33.462 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
27-4-17 11:01:33.462 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
27-4-17 11:01:33.462 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Thu Apr 27 11:01:33 UTC 2017, linkTarget=null, checksum=2a355a2b2b4bbac69e38a6c1b370782d125b1245, updated=Thu Apr 27 11:01:33 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
27-4-17 11:01:33.462 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file A4,B1
27-4-17 11:01:33.462 | 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=Thu Apr 27 11:01:33 UTC 2017, linkTarget=null, checksum=2a355a2b2b4bbac69e38a6c1b370782d125b1245, updated=Thu Apr 27 11:01:33 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-170427110008054-46179-client-C/A4,B1
27-4-17 11:01:33.462 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Thu Apr 27 11:01:33 UTC 2017, linkTarget=null, checksum=2a355a2b2b4bbac69e38a6c1b370782d125b1245, updated=Thu Apr 27 11:01:33 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
27-4-17 11:01:33.462 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
27-4-17 11:01:33.462 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=2, path=A3, type=FILE, status=DELETED, size=51200, lastModified=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=db017b97ff6e9e8df6c8ba9158064dd65824bc95, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
27-4-17 11:01:33.462 | FileVersionComp | Test worker    | INFO :      - []: Local file does not exist, and expected file was deleted, for file A3
27-4-17 11:01:33.462 | 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=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=db017b97ff6e9e8df6c8ba9158064dd65824bc95, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-170427110008054-46179-client-C/A3
27-4-17 11:01:33.462 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
27-4-17 11:01:33.462 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=6be7cf28a705f4ef3be486457ae0624fca1c4c20, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
27-4-17 11:01:33.463 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file A2
27-4-17 11:01:33.463 | 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=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=6be7cf28a705f4ef3be486457ae0624fca1c4c20, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-170427110008054-46179-client-C/A2
27-4-17 11:01:33.463 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=6be7cf28a705f4ef3be486457ae0624fca1c4c20, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
27-4-17 11:01:33.463 | DownOperation   | Test worker    | INFO :   + Adding multichunk b3cf40bc12f6ec5d06c12d2befe52e2c8703c945 to download list ...
27-4-17 11:01:33.463 | DownOperation   | Test worker    | INFO :   + Adding multichunk ae3a61fcfff78f7ead9c9522a6cae28e5e390983 to download list ...
27-4-17 11:01:33.463 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
27-4-17 11:01:33.463 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@7e5f1cb5) ...
27-4-17 11:01:33.464 | Downloader      | Test worker    | INFO :   + Downloading multichunk ae3a61fcfff78f7ead9c9522a6cae28e5e390983 ...
27-4-17 11:01:33.464 | Downloader      | Test worker    | INFO :   + Decrypting multichunk ae3a61fcfff78f7ead9c9522a6cae28e5e390983 ...
27-4-17 11:01:33.466 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk ae3a61fcfff78f7ead9c9522a6cae28e5e390983 ...
27-4-17 11:01:33.467 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@5fc09f76) ...
27-4-17 11:01:33.467 | Downloader      | Test worker    | INFO :   + Downloading multichunk b3cf40bc12f6ec5d06c12d2befe52e2c8703c945 ...
27-4-17 11:01:33.469 | Downloader      | Test worker    | INFO :   + Decrypting multichunk b3cf40bc12f6ec5d06c12d2befe52e2c8703c945 ...
27-4-17 11:01:33.469 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk b3cf40bc12f6ec5d06c12d2befe52e2c8703c945 ...
27-4-17 11:01:33.470 | FileSystemActio | Test worker    | INFO :    Sorted actions:
27-4-17 11:01:33.470 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=6be7cf28a705f4ef3be486457ae0624fca1c4c20, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
27-4-17 11:01:33.470 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Thu Apr 27 11:01:33 UTC 2017, linkTarget=null, checksum=2a355a2b2b4bbac69e38a6c1b370782d125b1245, updated=Thu Apr 27 11:01:33 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
27-4-17 11:01:33.470 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
27-4-17 11:01:33.470 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=3, path=A2, type=FILE, status=CHANGED, size=51200, lastModified=Thu Apr 27 11:01:32 UTC 2017, linkTarget=null, checksum=6be7cf28a705f4ef3be486457ae0624fca1c4c20, updated=Thu Apr 27 11:01:32 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
27-4-17 11:01:33.471 | Assembler       | Test worker    | INFO :      - Creating file A2 to /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/temp-reconstructedFileVersion-4876250900889115859.tmp ...
27-4-17 11:01:33.473 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
27-4-17 11:01:33.478 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=A4,B1, type=FILE, status=NEW, size=51200, lastModified=Thu Apr 27 11:01:33 UTC 2017, linkTarget=null, checksum=2a355a2b2b4bbac69e38a6c1b370782d125b1245, updated=Thu Apr 27 11:01:33 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
27-4-17 11:01:33.479 | Assembler       | Test worker    | INFO :      - Creating file A4,B1 to /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/temp-reconstructedFileVersion-7830767772378699039.tmp ...
27-4-17 11:01:33.481 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
27-4-17 11:01:33.481 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
27-4-17 11:01:33.481 | DownOperation   | Test worker    | INFO :   + Applying database version (A1)
27-4-17 11:01:33.481 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A1)/T=1493290892691, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
27-4-17 11:01:33.483 | DownOperation   | Test worker    | INFO :   + Applying database version (A2)
27-4-17 11:01:33.483 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A2)/T=1493290892744, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
27-4-17 11:01:33.484 | DownOperation   | Test worker    | INFO :   + Applying database version (A3)
27-4-17 11:01:33.484 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A3)/T=1493290892819, chunks=2, multiChunks=1, fileContents=2, fileHistories=2]
27-4-17 11:01:33.491 | DownOperation   | Test worker    | INFO :   + Applying database version (A4)
27-4-17 11:01:33.491 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=A/(A4)/T=1493290892867, chunks=0, multiChunks=0, fileContents=0, fileHistories=1]
27-4-17 11:01:33.492 | DownOperation   | Test worker    | INFO :   + Applying database version (A4,B1)
27-4-17 11:01:33.492 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=B/(A4,B1)/T=1493290893165, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
27-4-17 11:01:33.507 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-C-1493290893418] ...
27-4-17 11:01:33.511 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-C-1493290893418]
27-4-17 11:01:33.511 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
27-4-17 11:01:33.511 | Cache           | Test worker    | INFO : Cache size okay (156 KB), no need to clean (keep size is 500 MB)
27-4-17 11:01:33.511 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@5bbfe493) ...
27-4-17 11:01:33.511 | DownOperation   | Test worker    | INFO : Sync down done.
27-4-17 11:01:33.514 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.514 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-A' ...
27-4-17 11:01:33.514 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.514 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.514 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.514 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.514 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.514 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.515 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.515 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.515 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.515 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-A' ...
27-4-17 11:01:33.515 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.515 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.515 | TransferManager | Test worker    | INFO : - With feature PathAware
27-4-17 11:01:33.515 | TransferManager | Test worker    | INFO : - With feature TransactionAware
27-4-17 11:01:33.515 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.515 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.515 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.515 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.515 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.515 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.515 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
27-4-17 11:01:33.515 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
27-4-17 11:01:33.516 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.516 | UpOperation     | Test worker    | INFO : 
27-4-17 11:01:33.516 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client A ...
27-4-17 11:01:33.516 | UpOperation     | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.516 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@76ae745) ...
27-4-17 11:01:33.516 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.516 | StatusOperation | Test worker    | INFO : 
27-4-17 11:01:33.516 | StatusOperation | Test worker    | INFO : Running 'Status' at client A ...
27-4-17 11:01:33.516 | StatusOperation | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.516 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
27-4-17 11:01:33.516 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@46dcb20b) ...
27-4-17 11:01:33.517 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-170427110008054-46179-client-A ...
27-4-17 11:01:33.517 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
27-4-17 11:01:33.518 | StatusOperation | Test worker    | INFO : - No changes to local database
27-4-17 11:01:33.518 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@18ea3488) ...
27-4-17 11:01:33.518 | UpOperation     | Test worker    | INFO : Local database is up-to-date (change set). NOTHING TO DO!
27-4-17 11:01:33.518 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@12521c9c) ...
27-4-17 11:01:33.518 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.518 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-B' ...
27-4-17 11:01:33.518 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.518 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.518 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.518 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.518 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.518 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.518 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.518 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.518 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.518 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-B' ...
27-4-17 11:01:33.518 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.518 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.518 | TransferManager | Test worker    | INFO : - With feature PathAware
27-4-17 11:01:33.518 | TransferManager | Test worker    | INFO : - With feature TransactionAware
27-4-17 11:01:33.518 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.518 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.518 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.519 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.519 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.519 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.519 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
27-4-17 11:01:33.519 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
27-4-17 11:01:33.519 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.520 | UpOperation     | Test worker    | INFO : 
27-4-17 11:01:33.520 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client B ...
27-4-17 11:01:33.520 | UpOperation     | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.520 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@2de8b837) ...
27-4-17 11:01:33.520 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.520 | StatusOperation | Test worker    | INFO : 
27-4-17 11:01:33.520 | StatusOperation | Test worker    | INFO : Running 'Status' at client B ...
27-4-17 11:01:33.520 | StatusOperation | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.520 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
27-4-17 11:01:33.520 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@66dbc18b) ...
27-4-17 11:01:33.521 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-170427110008054-46179-client-B ...
27-4-17 11:01:33.521 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
27-4-17 11:01:33.521 | StatusOperation | Test worker    | INFO : - No changes to local database
27-4-17 11:01:33.521 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@1f130d15) ...
27-4-17 11:01:33.521 | UpOperation     | Test worker    | INFO : Local database is up-to-date (change set). NOTHING TO DO!
27-4-17 11:01:33.521 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@5571a276) ...
27-4-17 11:01:33.521 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.522 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-C' ...
27-4-17 11:01:33.522 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.522 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.522 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.522 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.522 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.522 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.522 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.522 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.522 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.522 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-C' ...
27-4-17 11:01:33.522 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.522 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.522 | TransferManager | Test worker    | INFO : - With feature PathAware
27-4-17 11:01:33.522 | TransferManager | Test worker    | INFO : - With feature TransactionAware
27-4-17 11:01:33.522 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.522 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.522 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.522 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.522 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.522 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.522 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
27-4-17 11:01:33.522 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
27-4-17 11:01:33.523 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.523 | UpOperation     | Test worker    | INFO : 
27-4-17 11:01:33.523 | UpOperation     | Test worker    | INFO : Running 'Sync up' at client C ...
27-4-17 11:01:33.523 | UpOperation     | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.523 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpStartSyncExternalEvent@226180a3) ...
27-4-17 11:01:33.524 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.524 | StatusOperation | Test worker    | INFO : 
27-4-17 11:01:33.524 | StatusOperation | Test worker    | INFO : Running 'Status' at client C ...
27-4-17 11:01:33.524 | StatusOperation | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.524 | StatusOperation | Test worker    | INFO : Querying current file tree from database ...
27-4-17 11:01:33.524 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusStartSyncExternalEvent (org.syncany.operations.daemon.messages.StatusStartSyncExternalEvent@7da73e88) ...
27-4-17 11:01:33.524 | StatusOperation | Test worker    | INFO : Analyzing local folder /tmp/syncanytest/syncany-170427110008054-46179-client-C ...
27-4-17 11:01:33.524 | StatusOperation | Test worker    | FINE : - Ignoring file (syncany app-related): .syncany
27-4-17 11:01:33.524 | StatusOperation | Test worker    | FINE : - New file: C1
27-4-17 11:01:33.525 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event StatusEndSyncExternalEvent (org.syncany.operations.daemon.messages.StatusEndSyncExternalEvent@2f15e712) ...
27-4-17 11:01:33.525 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
27-4-17 11:01:33.525 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.525 | LsRemoteOperati | Test worker    | INFO : 
27-4-17 11:01:33.525 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
27-4-17 11:01:33.525 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.525 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@46582c81) ...
27-4-17 11:01:33.526 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
27-4-17 11:01:33.526 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
27-4-17 11:01:33.526 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
27-4-17 11:01:33.526 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
27-4-17 11:01:33.526 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
27-4-17 11:01:33.526 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
27-4-17 11:01:33.526 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@52a254ab) ...
27-4-17 11:01:33.526 | UpOperation     | Test worker    | INFO : No remote changes, ready to upload.
27-4-17 11:01:33.526 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-up-C-1493290893522] ...
27-4-17 11:01:33.526 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-up-C-1493290893522]
27-4-17 11:01:33.526 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-up-C-1493290893522] ...
27-4-17 11:01:33.527 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.527 | TransactionAwar | Test worker    | INFO : Done rolling back previous transactions.
27-4-17 11:01:33.527 | AsyncIndexer    | AsyncI/syncany | INFO : Starting Indexing.
27-4-17 11:01:33.527 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexStartSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexStartSyncExternalEvent@125a2c2a) ...
27-4-17 11:01:33.527 | Indexer         | AsyncI/syncany | FINE : - Looking for deleted files ...
27-4-17 11:01:33.527 | Indexer         | AsyncI/syncany | FINE : - +File /tmp/syncanytest/syncany-170427110008054-46179-client-C/C1
27-4-17 11:01:33.528 | Indexer         | AsyncI/syncany | FINE : - +FileContent: /tmp/syncanytest/syncany-170427110008054-46179-client-C/C1
27-4-17 11:01:33.529 | Indexer         | AsyncI/syncany | FINE : - Chunk new: 3ea220d8cc01e25bf29c79f7cba775117ec6b052
27-4-17 11:01:33.529 | Indexer         | AsyncI/syncany | FINE : - +MultiChunk 138c1c876d96f9629f67f2fd3ed818e1d2f81d49
27-4-17 11:01:33.530 | Indexer         | AsyncI/syncany | FINE : - Chunk > MultiChunk: 3ea220d8cc01e25bf29c79f7cba775117ec6b052 > 138c1c876d96f9629f67f2fd3ed818e1d2f81d49
27-4-17 11:01:33.530 | Indexer         | AsyncI/syncany | FINE : - Chunk > FileContent: 3ea220d8cc01e25bf29c79f7cba775117ec6b052 > /tmp/syncanytest/syncany-170427110008054-46179-client-C/C1
27-4-17 11:01:33.530 | Indexer         | AsyncI/syncany | FINE : - /File: C1 (checksum 3ea220d8cc01e25bf29c79f7cba775117ec6b052)
27-4-17 11:01:33.531 | Indexer         | AsyncI/syncany | FINE :    * No old file history found, starting new history (path: C1, checksum: 3ea220d8cc01e25bf29c79f7cba775117ec6b052)
27-4-17 11:01:33.531 | FileVersionComp | AsyncI/syncany | INFO :      - [DELETED]: Local file DIFFERS from file version, actual file is NULL, for file C1
27-4-17 11:01:33.531 | Indexer         | AsyncI/syncany | INFO :    * Added file version:    FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Thu Apr 27 11:01:33 UTC 2017, linkTarget=null, checksum=3ea220d8cc01e25bf29c79f7cba775117ec6b052, updated=Thu Apr 27 11:01:33 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
27-4-17 11:01:33.531 | Indexer         | AsyncI/syncany | INFO :      based on file version: null
27-4-17 11:01:33.531 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexChangesDetectedSyncExternalEvent@762084dd) ...
27-4-17 11:01:33.531 | Indexer         | AsyncI/syncany | FINE : - /MultiChunk 138c1c876d96f9629f67f2fd3ed818e1d2f81d49
27-4-17 11:01:33.532 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexEndSyncExternalEvent@33338ab7) ...
27-4-17 11:01:33.532 | Indexer         | AsyncI/syncany | FINE : Processed new database version: DatabaseVersion [header=UnknownMachine/()/T=1493290893527, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
27-4-17 11:01:33.532 | UpOperation     | Test worker    | INFO : No DIRTY data found in database (no dirty databases); Nothing to do here.
27-4-17 11:01:33.532 | UpOperation     | Test worker    | INFO : Last vector clock was: (A4,B1)
27-4-17 11:01:33.532 | UpOperation     | Test worker    | INFO : Uploading new multichunks ...
27-4-17 11:01:33.532 | UpOperation     | Test worker    | INFO : - Uploading multichunk 138c1c876d96f9629f67f2fd3ed818e1d2f81d49 from /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/multichunk-138c1c876d96f9629f67f2fd3ed818e1d2f81d49 to RemoteFile[name=multichunk-138c1c876d96f9629f67f2fd3ed818e1d2f81d49] ...
27-4-17 11:01:33.532 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/multichunk-138c1c876d96f9629f67f2fd3ed818e1d2f81d49 -> Temp. remote file: RemoteFile[name=temp-PiLZf-multichunk-138c1c876d96f9629f67f2fd3ed818e1d2f81d49], final location: RemoteFile[name=multichunk-138c1c876d96f9629f67f2fd3ed818e1d2f81d49]
27-4-17 11:01:33.533 | UpOperation     | Test worker    | INFO : Uploading database: DatabaseVersion [header=C/(A4,B1,C1)/T=1493290893532, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
27-4-17 11:01:33.533 | UpOperation     | Test worker    | INFO : Saving local delta database, version C/(A4,B1,C1)/T=1493290893532 to file /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/database-C-0000000001 ... 
27-4-17 11:01:33.533 | UpOperation     | Test worker    | INFO : - Saving database to /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/database-C-0000000001 ...
27-4-17 11:01:33.534 | UpOperation     | Test worker    | INFO : - Uploading local delta database file ...
27-4-17 11:01:33.534 | UpOperation     | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/database-C-0000000001 to RemoteFile[name=database-C-0000000001] ...
27-4-17 11:01:33.534 | RemoteTransacti | Test worker    | INFO : - Adding file to TX for UPLOAD: /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/database-C-0000000001 -> Temp. remote file: RemoteFile[name=temp-wtsXH-database-C-0000000001], final location: RemoteFile[name=database-C-0000000001]
27-4-17 11:01:33.534 | UpOperation     | Test worker    | INFO : Adding shutdown hook (to allow resuming the upload) ...
27-4-17 11:01:33.534 | RemoteTransacti | Test worker    | INFO : Starting TX.commit() ...
27-4-17 11:01:33.535 | RemoteTransacti | Test worker    | INFO : Wrote transaction manifest to temporary file: /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/temp-transaction-971487687403637784.tmp
27-4-17 11:01:33.535 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileSyncExternalEvent@384fb5d7) ...
27-4-17 11:01:33.535 | RemoteTransacti | Test worker    | INFO : - Uploading remote transaction file RemoteFile[name=transaction-504ff624] ...
27-4-17 11:01:33.535 | RemoteTransacti | Test worker    | INFO : - Starting to upload data in commit.
27-4-17 11:01:33.536 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@266bf515) ...
27-4-17 11:01:33.536 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/multichunk-138c1c876d96f9629f67f2fd3ed818e1d2f81d49 to temp. file RemoteFile[name=temp-PiLZf-multichunk-138c1c876d96f9629f67f2fd3ed818e1d2f81d49] ...
27-4-17 11:01:33.536 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpUploadFileInTransactionSyncExternalEvent (org.syncany.operations.daemon.messages.UpUploadFileInTransactionSyncExternalEvent@6fae811d) ...
27-4-17 11:01:33.536 | RemoteTransacti | Test worker    | INFO : - Uploading /tmp/syncanytest/syncany-170427110008054-46179-client-C/.syncany/cache/database-C-0000000001 to temp. file RemoteFile[name=temp-wtsXH-database-C-0000000001] ...
27-4-17 11:01:33.536 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-PiLZf-multichunk-138c1c876d96f9629f67f2fd3ed818e1d2f81d49] to final location RemoteFile[name=multichunk-138c1c876d96f9629f67f2fd3ed818e1d2f81d49] ...
27-4-17 11:01:33.536 | RemoteTransacti | Test worker    | INFO : - Moving temp. file RemoteFile[name=temp-wtsXH-database-C-0000000001] to final location RemoteFile[name=database-C-0000000001] ...
27-4-17 11:01:33.536 | RemoteTransacti | Test worker    | INFO : - Deleting remote transaction file RemoteFile[name=transaction-504ff624] ...
27-4-17 11:01:33.537 | RemoteTransacti | Test worker    | INFO : END of TX.commmit(): Succesfully committed transaction.
27-4-17 11:01:33.537 | RemoteTransacti | Test worker    | INFO : END of TX.delTemp(): Sucessfully deleted final files.
27-4-17 11:01:33.537 | UpOperation     | Test worker    | INFO : Persisting local SQL database (new database version C/(A4,B1,C1)/T=1493290893532) ...
27-4-17 11:01:33.538 | UpOperation     | Test worker    | INFO : Removing DIRTY database versions from database ...
27-4-17 11:01:33.539 | InternalEventBu | AsyncI/syncany | INFO : Event bus 'LocalEventBus': Posting event UpIndexMidSyncExternalEvent (org.syncany.operations.daemon.messages.UpIndexMidSyncExternalEvent@2b5b2876) ...
27-4-17 11:01:33.543 | AsyncIndexer    | AsyncI/syncany | INFO : Stopping indexing. Signal end of stream with empty databaseversion
27-4-17 11:01:33.545 | UpOperation     | Test worker    | INFO : Adding database version to result changes:DatabaseVersion [header=C/(A4,B1,C1)/T=1493290893532, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
27-4-17 11:01:33.545 | UpOperation     | Test worker    | INFO : Committing local database.
27-4-17 11:01:33.545 | UpOperation     | Test worker    | FINE : Waiting for new database version.
27-4-17 11:01:33.545 | UpOperation     | Test worker    | FINE : Took new database version: DatabaseVersion [header=UnknownMachine/()/T=1493290893543, chunks=0, multiChunks=0, fileContents=0, fileHistories=0]
27-4-17 11:01:33.545 | UpOperation     | Test worker    | INFO : Sync up done.
27-4-17 11:01:33.547 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-up-C-1493290893522] ...
27-4-17 11:01:33.548 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-up-C-1493290893522]
27-4-17 11:01:33.548 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
27-4-17 11:01:33.548 | Cache           | Test worker    | INFO : Cache size okay (207 KB), no need to clean (keep size is 500 MB)
27-4-17 11:01:33.548 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event UpEndSyncExternalEvent (org.syncany.operations.daemon.messages.UpEndSyncExternalEvent@36a9f8c) ...
27-4-17 11:01:33.548 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.548 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-A' ...
27-4-17 11:01:33.548 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.548 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.548 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.549 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.549 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.549 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.549 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.549 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.549 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.549 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-A' ...
27-4-17 11:01:33.549 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.549 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.549 | TransferManager | Test worker    | INFO : - With feature PathAware
27-4-17 11:01:33.549 | TransferManager | Test worker    | INFO : - With feature TransactionAware
27-4-17 11:01:33.549 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.549 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.549 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.549 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.549 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.549 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.549 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
27-4-17 11:01:33.549 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
27-4-17 11:01:33.550 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.550 | DownOperation   | Test worker    | INFO : 
27-4-17 11:01:33.550 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client A ...
27-4-17 11:01:33.550 | DownOperation   | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.550 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@1b76d8c) ...
27-4-17 11:01:33.550 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
27-4-17 11:01:33.551 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.551 | LsRemoteOperati | Test worker    | INFO : 
27-4-17 11:01:33.551 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client A ...
27-4-17 11:01:33.551 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.551 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@3dbbe3b0) ...
27-4-17 11:01:33.551 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
27-4-17 11:01:33.551 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
27-4-17 11:01:33.551 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
27-4-17 11:01:33.551 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
27-4-17 11:01:33.551 | LsRemoteOperati | Test worker    | INFO : - Remote database database-C-0000000001 is new.
27-4-17 11:01:33.551 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
27-4-17 11:01:33.551 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
27-4-17 11:01:33.551 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@65e34fa1) ...
27-4-17 11:01:33.551 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@5b9be2e6) ...
27-4-17 11:01:33.551 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-A-1493290893549] ...
27-4-17 11:01:33.551 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-A-1493290893549]
27-4-17 11:01:33.551 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-A-1493290893549] ...
27-4-17 11:01:33.552 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
27-4-17 11:01:33.552 | DownOperation   | Test worker    | INFO : - Downloading database-C-0000000001 to local cache at /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-C-0000000001
27-4-17 11:01:33.552 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@de16a19) ...
27-4-17 11:01:33.552 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
27-4-17 11:01:33.552 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-C-0000000001 ...
27-4-17 11:01:33.554 | DatabaseXmlPars | Test worker    | INFO :    + Added database version C/(A4,B1,C1)/T=1493290893532
27-4-17 11:01:33.554 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-C-0000000001; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.554 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.554 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.554 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.554 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.554 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.554 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
27-4-17 11:01:33.554 | DownOperation   | Test worker    | INFO : Populated unknown branches: {A=[A/(A1)/T=1493290892691, A/(A2)/T=1493290892744, A/(A3)/T=1493290892819, A/(A4)/T=1493290892867, B/(A4,B1)/T=1493290893165], C=[C/(A4,B1,C1)/T=1493290893532]}
27-4-17 11:01:33.554 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
27-4-17 11:01:33.555 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1493290892691
27-4-17 11:01:33.555 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1493290892744
27-4-17 11:01:33.555 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3)/T=1493290892819
27-4-17 11:01:33.555 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A4)/T=1493290892867
27-4-17 11:01:33.555 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A4,B1)/T=1493290893165
27-4-17 11:01:33.555 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: C/(A4,B1,C1)/T=1493290893532
27-4-17 11:01:33.555 | DatabaseReconci | Test worker    | INFO : - Winner is C with branch: 
27-4-17 11:01:33.555 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1493290892691
27-4-17 11:01:33.555 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1493290892744
27-4-17 11:01:33.555 | DatabaseReconci | Test worker    | INFO :   + A/(A3)/T=1493290892819
27-4-17 11:01:33.555 | DatabaseReconci | Test worker    | INFO :   + A/(A4)/T=1493290892867
27-4-17 11:01:33.555 | DatabaseReconci | Test worker    | INFO :   + B/(A4,B1)/T=1493290893165
27-4-17 11:01:33.555 | DatabaseReconci | Test worker    | INFO :   + C/(A4,B1,C1)/T=1493290893532
27-4-17 11:01:33.555 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
27-4-17 11:01:33.555 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
27-4-17 11:01:33.555 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
27-4-17 11:01:33.555 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1493290892691, A/(A2)/T=1493290892744, A/(A3)/T=1493290892819, A/(A4)/T=1493290892867, B/(A4,B1)/T=1493290893165]
27-4-17 11:01:33.555 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1493290892691, A/(A2)/T=1493290892744, A/(A3)/T=1493290892819, A/(A4)/T=1493290892867, B/(A4,B1)/T=1493290893165, C/(A4,B1,C1)/T=1493290893532]
27-4-17 11:01:33.555 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
27-4-17 11:01:33.555 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [C/(A4,B1,C1)/T=1493290893532]
27-4-17 11:01:33.555 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
27-4-17 11:01:33.555 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/database-C-0000000001 ...
27-4-17 11:01:33.556 | DatabaseXmlPars | Test worker    | INFO :    + Added database version C/(A4,B1,C1)/T=1493290893532
27-4-17 11:01:33.556 | DownOperation   | Test worker    | INFO : Determine file system actions ...
27-4-17 11:01:33.557 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.557 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
27-4-17 11:01:33.557 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
27-4-17 11:01:33.557 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
27-4-17 11:01:33.558 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Thu Apr 27 11:01:33 UTC 2017, linkTarget=null, checksum=3ea220d8cc01e25bf29c79f7cba775117ec6b052, updated=Thu Apr 27 11:01:33 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
27-4-17 11:01:33.558 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file C1
27-4-17 11:01:33.558 | 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=Thu Apr 27 11:01:33 UTC 2017, linkTarget=null, checksum=3ea220d8cc01e25bf29c79f7cba775117ec6b052, updated=Thu Apr 27 11:01:33 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-170427110008054-46179-client-A/C1
27-4-17 11:01:33.558 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Thu Apr 27 11:01:33 UTC 2017, linkTarget=null, checksum=3ea220d8cc01e25bf29c79f7cba775117ec6b052, updated=Thu Apr 27 11:01:33 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
27-4-17 11:01:33.558 | DownOperation   | Test worker    | INFO :   + Adding multichunk 138c1c876d96f9629f67f2fd3ed818e1d2f81d49 to download list ...
27-4-17 11:01:33.558 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
27-4-17 11:01:33.558 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@75b3ebad) ...
27-4-17 11:01:33.558 | Downloader      | Test worker    | INFO :   + Downloading multichunk 138c1c876d96f9629f67f2fd3ed818e1d2f81d49 ...
27-4-17 11:01:33.559 | Downloader      | Test worker    | INFO :   + Decrypting multichunk 138c1c876d96f9629f67f2fd3ed818e1d2f81d49 ...
27-4-17 11:01:33.559 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk 138c1c876d96f9629f67f2fd3ed818e1d2f81d49 ...
27-4-17 11:01:33.560 | FileSystemActio | Test worker    | INFO :    Sorted actions:
27-4-17 11:01:33.560 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Thu Apr 27 11:01:33 UTC 2017, linkTarget=null, checksum=3ea220d8cc01e25bf29c79f7cba775117ec6b052, updated=Thu Apr 27 11:01:33 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
27-4-17 11:01:33.560 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
27-4-17 11:01:33.560 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Thu Apr 27 11:01:33 UTC 2017, linkTarget=null, checksum=3ea220d8cc01e25bf29c79f7cba775117ec6b052, updated=Thu Apr 27 11:01:33 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
27-4-17 11:01:33.560 | Assembler       | Test worker    | INFO :      - Creating file C1 to /tmp/syncanytest/syncany-170427110008054-46179-client-A/.syncany/cache/temp-reconstructedFileVersion-6030194779945097875.tmp ...
27-4-17 11:01:33.561 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
27-4-17 11:01:33.562 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
27-4-17 11:01:33.562 | DownOperation   | Test worker    | INFO :   + Applying database version (A4,B1,C1)
27-4-17 11:01:33.562 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=C/(A4,B1,C1)/T=1493290893532, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
27-4-17 11:01:33.574 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-A-1493290893549] ...
27-4-17 11:01:33.581 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-A-1493290893549]
27-4-17 11:01:33.581 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
27-4-17 11:01:33.582 | Cache           | Test worker    | INFO : Cache size okay (257 KB), no need to clean (keep size is 500 MB)
27-4-17 11:01:33.582 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@6a67f6c3) ...
27-4-17 11:01:33.582 | DownOperation   | Test worker    | INFO : Sync down done.
27-4-17 11:01:33.582 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.582 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-B' ...
27-4-17 11:01:33.582 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.582 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.582 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.582 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.583 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.583 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.583 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.583 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.583 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.583 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-B' ...
27-4-17 11:01:33.583 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.583 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.583 | TransferManager | Test worker    | INFO : - With feature PathAware
27-4-17 11:01:33.583 | TransferManager | Test worker    | INFO : - With feature TransactionAware
27-4-17 11:01:33.584 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.584 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.584 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.584 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.584 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.584 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.584 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
27-4-17 11:01:33.584 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
27-4-17 11:01:33.588 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.588 | DownOperation   | Test worker    | INFO : 
27-4-17 11:01:33.588 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client B ...
27-4-17 11:01:33.588 | DownOperation   | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.588 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@3f8c783b) ...
27-4-17 11:01:33.588 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
27-4-17 11:01:33.589 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.589 | LsRemoteOperati | Test worker    | INFO : 
27-4-17 11:01:33.589 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client B ...
27-4-17 11:01:33.589 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.589 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@121d246a) ...
27-4-17 11:01:33.589 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
27-4-17 11:01:33.590 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
27-4-17 11:01:33.590 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
27-4-17 11:01:33.590 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
27-4-17 11:01:33.590 | LsRemoteOperati | Test worker    | INFO : - Remote database database-C-0000000001 is new.
27-4-17 11:01:33.590 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
27-4-17 11:01:33.590 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
27-4-17 11:01:33.590 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@4a3de385) ...
27-4-17 11:01:33.590 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownChangesDetectedSyncExternalEvent (org.syncany.operations.daemon.messages.DownChangesDetectedSyncExternalEvent@45b6cdd5) ...
27-4-17 11:01:33.590 | ActionFileHandl | Test worker    | INFO : Starting action for RemoteFile[name=action-down-B-1493290893584] ...
27-4-17 11:01:33.590 | ActionFileHandl | Test worker    | INFO : Uploading action file: RemoteFile[name=action-down-B-1493290893584]
27-4-17 11:01:33.590 | ActionFileHandl | Test worker    | INFO : Scheduling action renewal task for every 2 minutes, for RemoteFile[name=action-down-B-1493290893584] ...
27-4-17 11:01:33.591 | DownOperation   | Test worker    | INFO : Downloading unknown databases.
27-4-17 11:01:33.591 | DownOperation   | Test worker    | INFO : - Downloading database-C-0000000001 to local cache at /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/database-C-0000000001
27-4-17 11:01:33.591 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@6d4bf5fb) ...
27-4-17 11:01:33.591 | DownOperation   | Test worker    | INFO : Loading database headers, creating branches ...
27-4-17 11:01:33.591 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (HEADER_ONLY) from file /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/database-C-0000000001 ...
27-4-17 11:01:33.593 | DatabaseXmlPars | Test worker    | INFO :    + Added database version C/(A4,B1,C1)/T=1493290893532
27-4-17 11:01:33.593 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-C-0000000001; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.593 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-B-0000000001; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.593 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-A-0000000004; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.594 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-A-0000000002; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.594 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-A-0000000001; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.594 | LocalTransferMa | Test worker    | INFO : Cannot create instance of CleanupRemoteFile for file /tmp/syncanytest/syncany-170427110008054-46179-repo/databases/database-A-0000000003; maybe invalid file name pattern. Ignoring file.
27-4-17 11:01:33.594 | ApplicationSqlD | Test worker    | INFO : SQL (general_settings): Read cleanupNumber  = (not set)
27-4-17 11:01:33.594 | DownOperation   | Test worker    | INFO : Populated unknown branches: {B=[A/(A1)/T=1493290892691, A/(A2)/T=1493290892744, A/(A3)/T=1493290892819, A/(A4)/T=1493290892867, B/(A4,B1)/T=1493290893165], C=[C/(A4,B1,C1)/T=1493290893532]}
27-4-17 11:01:33.594 | DownOperation   | Test worker    | INFO : Determine winner using database reconciliator ...
27-4-17 11:01:33.595 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A1)/T=1493290892691
27-4-17 11:01:33.595 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A2)/T=1493290892744
27-4-17 11:01:33.595 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A3)/T=1493290892819
27-4-17 11:01:33.595 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: A/(A4)/T=1493290892867
27-4-17 11:01:33.595 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: B/(A4,B1)/T=1493290893165
27-4-17 11:01:33.595 | DatabaseReconci | Test worker    | INFO : Adding database version to winning branch: C/(A4,B1,C1)/T=1493290893532
27-4-17 11:01:33.595 | DatabaseReconci | Test worker    | INFO : - Winner is C with branch: 
27-4-17 11:01:33.595 | DatabaseReconci | Test worker    | INFO :   + A/(A1)/T=1493290892691
27-4-17 11:01:33.595 | DatabaseReconci | Test worker    | INFO :   + A/(A2)/T=1493290892744
27-4-17 11:01:33.595 | DatabaseReconci | Test worker    | INFO :   + A/(A3)/T=1493290892819
27-4-17 11:01:33.595 | DatabaseReconci | Test worker    | INFO :   + A/(A4)/T=1493290892867
27-4-17 11:01:33.595 | DatabaseReconci | Test worker    | INFO :   + B/(A4,B1)/T=1493290893165
27-4-17 11:01:33.596 | DatabaseReconci | Test worker    | INFO :   + C/(A4,B1,C1)/T=1493290893532
27-4-17 11:01:33.596 | DownOperation   | Test worker    | INFO : - Database versions to REMOVE locally: []
27-4-17 11:01:33.596 | DownOperation   | Test worker    | INFO :   + Nothing to purge locally. No conflicts. Only updates. Nice!
27-4-17 11:01:33.596 | DatabaseReconci | Test worker    | INFO : Finding winnersApplyBranch.
27-4-17 11:01:33.596 | DatabaseReconci | Test worker    | INFO : Losers Branch: [A/(A1)/T=1493290892691, A/(A2)/T=1493290892744, A/(A3)/T=1493290892819, A/(A4)/T=1493290892867, B/(A4,B1)/T=1493290893165]
27-4-17 11:01:33.596 | DatabaseReconci | Test worker    | INFO : Winners Branch: [A/(A1)/T=1493290892691, A/(A2)/T=1493290892744, A/(A3)/T=1493290892819, A/(A4)/T=1493290892867, B/(A4,B1)/T=1493290893165, C/(A4,B1,C1)/T=1493290893532]
27-4-17 11:01:33.596 | DownOperation   | Test worker    | INFO : - Cleanup occurred: false
27-4-17 11:01:33.596 | DownOperation   | Test worker    | INFO : - Database versions to APPLY locally: [C/(A4,B1,C1)/T=1493290893532]
27-4-17 11:01:33.596 | DownOperation   | Test worker    | INFO : Loading winners database (DEFAULT) ...
27-4-17 11:01:33.596 | DatabaseXmlSeri | Test worker    | INFO : - Loading database (FULL) from file /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/database-C-0000000001 ...
27-4-17 11:01:33.598 | DatabaseXmlPars | Test worker    | INFO :    + Added database version C/(A4,B1,C1)/T=1493290893532
27-4-17 11:01:33.601 | DownOperation   | Test worker    | INFO : Determine file system actions ...
27-4-17 11:01:33.602 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.603 | FileSystemActio | Test worker    | INFO : - Loading current file tree...
27-4-17 11:01:33.603 | FileSystemActio | Test worker    | INFO : - Determine filesystem actions ...
27-4-17 11:01:33.603 | FileSystemActio | Test worker    | INFO :   + Comparing local version: null
27-4-17 11:01:33.603 | FileSystemActio | Test worker    | INFO :     with winning version   : FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Thu Apr 27 11:01:33 UTC 2017, linkTarget=null, checksum=3ea220d8cc01e25bf29c79f7cba775117ec6b052, updated=Thu Apr 27 11:01:33 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]
27-4-17 11:01:33.604 | FileVersionComp | Test worker    | INFO :      - [DELETED]: Local file DIFFERS from file version, expected EXISTS = true, but actual EXISTS = false, for file C1
27-4-17 11:01:33.604 | 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=Thu Apr 27 11:01:33 UTC 2017, linkTarget=null, checksum=3ea220d8cc01e25bf29c79f7cba775117ec6b052, updated=Thu Apr 27 11:01:33 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-] AND /tmp/syncanytest/syncany-170427110008054-46179-client-B/C1
27-4-17 11:01:33.604 | FileSystemActio | Test worker    | INFO :      -> NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Thu Apr 27 11:01:33 UTC 2017, linkTarget=null, checksum=3ea220d8cc01e25bf29c79f7cba775117ec6b052, updated=Thu Apr 27 11:01:33 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
27-4-17 11:01:33.605 | DownOperation   | Test worker    | INFO :   + Adding multichunk 138c1c876d96f9629f67f2fd3ed818e1d2f81d49 to download list ...
27-4-17 11:01:33.605 | Downloader      | Test worker    | INFO : Downloading and extracting multichunks ...
27-4-17 11:01:33.605 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownDownloadFileSyncExternalEvent (org.syncany.operations.daemon.messages.DownDownloadFileSyncExternalEvent@597a8757) ...
27-4-17 11:01:33.605 | Downloader      | Test worker    | INFO :   + Downloading multichunk 138c1c876d96f9629f67f2fd3ed818e1d2f81d49 ...
27-4-17 11:01:33.606 | Downloader      | Test worker    | INFO :   + Decrypting multichunk 138c1c876d96f9629f67f2fd3ed818e1d2f81d49 ...
27-4-17 11:01:33.609 | Downloader      | Test worker    | FINE :   + Locally deleting multichunk 138c1c876d96f9629f67f2fd3ed818e1d2f81d49 ...
27-4-17 11:01:33.609 | FileSystemActio | Test worker    | INFO :    Sorted actions:
27-4-17 11:01:33.609 | FileSystemActio | Test worker    | INFO :    + NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Thu Apr 27 11:01:33 UTC 2017, linkTarget=null, checksum=3ea220d8cc01e25bf29c79f7cba775117ec6b052, updated=Thu Apr 27 11:01:33 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
27-4-17 11:01:33.610 | DownOperation   | Test worker    | FINE : - Applying file system actions (sorted!) ...
27-4-17 11:01:33.610 | DownOperation   | Test worker    | FINE :    +  NewFileSystemAction [file1=null, file2=FileVersion [version=1, path=C1, type=FILE, status=NEW, size=51200, lastModified=Thu Apr 27 11:01:33 UTC 2017, linkTarget=null, checksum=3ea220d8cc01e25bf29c79f7cba775117ec6b052, updated=Thu Apr 27 11:01:33 UTC 2017, posixPermissions=rw-rw-r--, dosAttributes=--a-]]
27-4-17 11:01:33.610 | Assembler       | Test worker    | INFO :      - Creating file C1 to /tmp/syncanytest/syncany-170427110008054-46179-client-B/.syncany/cache/temp-reconstructedFileVersion-8087983509891400134.tmp ...
27-4-17 11:01:33.611 | FileSystemActio | Test worker    | INFO :      - Setting POSIX permissions: rw-rw-r-- ...
27-4-17 11:01:33.612 | DownOperation   | Test worker    | INFO : - Adding database versions to SQL database ...
27-4-17 11:01:33.612 | DownOperation   | Test worker    | INFO :   + Applying database version (A4,B1,C1)
27-4-17 11:01:33.612 | DownOperation   | Test worker    | FINE :   + Contents: DatabaseVersion [header=C/(A4,B1,C1)/T=1493290893532, chunks=1, multiChunks=1, fileContents=1, fileHistories=1]
27-4-17 11:01:33.624 | ActionFileHandl | Test worker    | INFO : Finishing action for RemoteFile[name=action-down-B-1493290893584] ...
27-4-17 11:01:33.628 | ActionFileHandl | Test worker    | INFO : Deleting action file: RemoteFile[name=action-down-B-1493290893584]
27-4-17 11:01:33.629 | AbstractTransfe | Test worker    | INFO : Cleaning own old action files ...
27-4-17 11:01:33.630 | Cache           | Test worker    | INFO : Cache size okay (207 KB), no need to clean (keep size is 500 MB)
27-4-17 11:01:33.630 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@66229440) ...
27-4-17 11:01:33.630 | DownOperation   | Test worker    | INFO : Sync down done.
27-4-17 11:01:33.630 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.630 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-C' ...
27-4-17 11:01:33.630 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.630 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.630 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.630 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.630 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.630 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.630 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.630 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.630 | org.syncany.plu | Test worker    | FINE : Validating required fields
27-4-17 11:01:33.630 | TransferManager | Test worker    | INFO : Building LocalTransferManager from config 'syncany-170427110008054-46179-client-C' ...
27-4-17 11:01:33.630 | TransferManager | Test worker    | INFO : - With feature ReadAfterWriteConsistent
27-4-17 11:01:33.630 | TransferManager | Test worker    | INFO : - With feature Retriable
27-4-17 11:01:33.630 | TransferManager | Test worker    | INFO : - With feature PathAware
27-4-17 11:01:33.630 | TransferManager | Test worker    | INFO : - With feature TransactionAware
27-4-17 11:01:33.630 | TransferManager | Test worker    | FINE : - Checking if selected features supported ...
27-4-17 11:01:33.630 | TransferManager | Test worker    | FINE : - Checking for duplicate features ...
27-4-17 11:01:33.630 | TransferManager | Test worker    | FINE : - Checking required feature TransactionAware in LocalTransferManager ...
27-4-17 11:01:33.630 | TransferManager | Test worker    | FINE : - Checking required feature Retriable in LocalTransferManager ...
27-4-17 11:01:33.631 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature ReadAfterWriteConsistent
27-4-17 11:01:33.631 | TransferManager | Test worker    | FINE : - Wrapping TransferManager LocalTransferManager in RetriableFeatureTransferManager
27-4-17 11:01:33.631 | TransferManager | Test worker    | INFO : - SKIPPING unsupported optional feature PathAware
27-4-17 11:01:33.631 | TransferManager | Test worker    | FINE : - Wrapping TransferManager RetriableFeatureTransferManager in TransactionAwareFeatureTransferManager
27-4-17 11:01:33.638 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.638 | DownOperation   | Test worker    | INFO : 
27-4-17 11:01:33.638 | DownOperation   | Test worker    | INFO : Running 'Sync down' at client C ...
27-4-17 11:01:33.638 | DownOperation   | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.638 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownStartSyncExternalEvent (org.syncany.operations.daemon.messages.DownStartSyncExternalEvent@21b475a5) ...
27-4-17 11:01:33.638 | AbstractTransfe | Test worker    | INFO : Looking for other running remote operations ...
27-4-17 11:01:33.639 | DatabaseConnect | Test worker    | INFO : Found 12 tables.
27-4-17 11:01:33.639 | LsRemoteOperati | Test worker    | INFO : 
27-4-17 11:01:33.639 | LsRemoteOperati | Test worker    | INFO : Running 'Remote Status' at client C ...
27-4-17 11:01:33.639 | LsRemoteOperati | Test worker    | INFO : --------------------------------------------
27-4-17 11:01:33.639 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteStartSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteStartSyncExternalEvent@369c12fa) ...
27-4-17 11:01:33.639 | LsRemoteOperati | Test worker    | INFO : Retrieving remote database list.
27-4-17 11:01:33.639 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000004 is already known (in local database). Ignoring.
27-4-17 11:01:33.639 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000002 is already known (in local database). Ignoring.
27-4-17 11:01:33.639 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000003 is already known (in local database). Ignoring.
27-4-17 11:01:33.639 | LsRemoteOperati | Test worker    | INFO : - Remote database database-C-0000000001 is already known (in local database). Ignoring.
27-4-17 11:01:33.639 | LsRemoteOperati | Test worker    | INFO : - Remote database database-B-0000000001 is already known (in local database). Ignoring.
27-4-17 11:01:33.639 | LsRemoteOperati | Test worker    | INFO : - Remote database database-A-0000000001 is already known (in local database). Ignoring.
27-4-17 11:01:33.639 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event LsRemoteEndSyncExternalEvent (org.syncany.operations.daemon.messages.LsRemoteEndSyncExternalEvent@7fd09c23) ...
27-4-17 11:01:33.640 | DownOperation   | Test worker    | INFO : * Nothing new. Skipping down operation.
27-4-17 11:01:33.640 | InternalEventBu | Test worker    | INFO : Event bus 'LocalEventBus': Posting event DownEndSyncExternalEvent (org.syncany.operations.daemon.messages.DownEndSyncExternalEvent@4bff0e7c) ...
27-4-17 11:01:33.645 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-170427110008054-46179-client-A/A2, but actual PATH = tmp/syncanytest/syncany-170427110008054-46179-client-B/A2, for file tmp/syncanytest/syncany-170427110008054-46179-client-B/A2
27-4-17 11:01:33.647 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-170427110008054-46179-client-A/A4,B1, but actual PATH = tmp/syncanytest/syncany-170427110008054-46179-client-B/A4,B1, for file tmp/syncanytest/syncany-170427110008054-46179-client-B/A4,B1
27-4-17 11:01:33.649 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-170427110008054-46179-client-A/C1, but actual PATH = tmp/syncanytest/syncany-170427110008054-46179-client-B/C1, for file tmp/syncanytest/syncany-170427110008054-46179-client-B/C1
27-4-17 11:01:33.662 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-170427110008054-46179-client-B/A2, but actual PATH = tmp/syncanytest/syncany-170427110008054-46179-client-C/A2, for file tmp/syncanytest/syncany-170427110008054-46179-client-C/A2
27-4-17 11:01:33.666 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-170427110008054-46179-client-B/A4,B1, but actual PATH = tmp/syncanytest/syncany-170427110008054-46179-client-C/A4,B1, for file tmp/syncanytest/syncany-170427110008054-46179-client-C/A4,B1
27-4-17 11:01:33.668 | FileVersionComp | Test worker    | INFO :      - [CHANGED_PATH]: Local file DIFFERS from file version, expected PATH = tmp/syncanytest/syncany-170427110008054-46179-client-B/C1, but actual PATH = tmp/syncanytest/syncany-170427110008054-46179-client-C/C1, for file tmp/syncanytest/syncany-170427110008054-46179-client-C/C1